Jump to content

[Skyrim] Interpreting Papyrus Log Errors


Arthmoor

Recommended Posts

Interpreting Papyrus Log Errors



So we've all obviously seen them. Log files filled with garbage that you suspect is making your game do weird things. Loads and loads of errors, warnings, and just plain weird messages that don't make a lot of sense. We've seen just about everything here both through the USKP tracker and via other sources for strange things that break Papyrus. I've gone fishing through what Google could turn up from various logs posted to Pastebin.com as well as our own tracker reports to hopefully bring some sense to the process of figuring out what an error message in your log means.

If you happen to see something from your own work, I'm not picking on you. I grabbed what was available as examples. Plenty of other mods have them too. The goal here is hopefully to shed some light on how mod authors can fix them, and how users can help mod authors narrow down the more egregious cases.
 
If anything in this guide is not accurate or you can provide additional information, please do so! The more we all know, the better things will get.

Now, on to the various errors that can come up. Listed in no particular order because I simply grabbed examples as they became available. Please note these are general examples. Your errors obviously won't match the ones I've listed, just look for things that say the same or similar things.

Errors While Loading a Save
 

[06/19/2014 - 03:03:57PM] error: Native function GetEquippedObject in empty state could find no matching function on linked type Actor. Function will not be bound.

Generally this type of error indicates that some portion of the engine (or the SKSE dll in this case) is expecting a certain function name to exist, but the compiled Papyrus files available to it do not have the information in them. Anything that would depend on these kinds of functions to operate will break. It would be highly unusual for this to occur in a standard mod that's not leveraging a custom DLL file of some kind. It almost always means SKSE is not properly reinstalled and will resolve itself once it has been.
 

[02/24/2015 - 10:29:10PM] Warning: Variable ::VampireQuest_var on script ARTH_LAL_TriggerScript loaded from save not found within the actual object. This variable will be skipped.

This is harmless, and probably a good thing if it happened after an update. It generally indicates the author removed a property they're no longer using and Papyrus is cleaning up the leftovers. If the mod these belong to did NOT get updated, then you have a problem and it could evolve into something serious if it's ignored and you keep playing.
 

[02/24/2015 - 10:29:10PM] Cannot open store for class "ARTH_RRF_OrphanHanderScript", missing file?
[02/24/2015 - 10:29:10PM] Warning: Unable to get type ARTH_RRF_OrphanHanderScript referenced by the save game. Objects of this type will not be loaded.
[02/24/2015 - 10:29:10PM] Warning: Could not find type ARTH_RRF_OrphanHanderScript in the type table in save

This is what's known as an orphaned script (pun not intended here btw). It is caused either by uninstalling a mod, or by updating a mod which no longer has the mentioned script. It is generally harmless, but can sometimes be the cause of a CTD.
 

[01/28/2015 - 10:14:39AM] Error: Unable to bind script DLC2WaterScript to alias Water on quest DLC2TTF2 (0401AAC8) because their base types do not match.

This error is caused by a script extending one type but being used on an incorrect type. In this particular instance, DLC2WaterScript incorrectly extended ObjectReference when it should have extended ReferenceAlias. This is an error that must be corrected by the mod's author. It should self correct when the game loads after it's been fixed, but only once the content is no longer actively being used.
 

[02/11/2015 - 08:23:22PM] Error: Property Initiate1Alias on script uskpretroactive204script attached to USKPRetroactive204 (02012C3A) cannot be bound because alias Initiate1Alias on quest DarkBrotherhood (0001EA5C) is not the right type.

This error is related to the above and occurs when a script has been set to attach to the wrong type of object (ie: a Quest script on an Objectrefence, etc.) and thus cannot be properly enabled by the game. If it's a well known mod (like the USKP in this instance) the cause is almost always going to be a conflict from another mod which has overwritten some of the data needed by the game. It can also be caused by the save game retaining data from an uninstalled mod. On rare occasions, authors may do this deliberately, but it has not been demonstrated to behave properly and may lead to errors in cases where that's been done.
 

[06/19/2014 - 03:14:39PM] Error: Property LackMessage on script AATreasureMiscScript attached to  (C50614F9) cannot be bound because <NULL form> (C503C770) is not the right type.

Also somewhat related to the above two. This type of specific error where "NULL FORM" is mentioned tends to happen when a mod author removes a form (C503C770 in this case) from their mod but has not updated the properties on the ESP to remove the now deleted form.
 

[01/28/2015 - 10:14:39AM] warning: Property AshSpawnAttachChancePercent on script DLC2AshSpawnAttackChanceScript attached to alias Player on quest DLC2Init (04016E02) cannot be initialized because the script no longer contains that property.

This is actually an error generated because of an ESP rather than a script. It means the script was recompiled, a property was removed, but the ESP that accompanies it was not properly updated to remove the property. This is easily fixed by the mod's author. It will cause no damage, but it's annoying, and definitely not correct.
 

[02/06/2015 - 07:35:27PM] warning: Function fxDustDropRandomSCRIPT..OnLoad in stack frame 0 in stack 4266 differs from the in-game resource files - using version from save

This is caused by a script that was actively being run when the game saved and has since been updated in the mod. This will continue to happen with each game load until the object causing it is encountered again while playing. Not every type of script this problem shows up in will do that though and options become limited if the script is from the vanilla game.
 

[02/24/2015 - 10:29:10PM] Error: File "HearthfireMultiKid.esp" does not exist or is not currently loaded.
stack:
    <unknown self>.Game.GetFormFromFile() - "<native>" Line ?
    [ARTHRRFMoveFamilyToSeverinManor (4F0036C9)].arth_rrf_storeregistration.ModSupportChecks() - "ARTH_RRF_StoreRegistration.psc" Line 50
    [alias Player on quest ARTHRRFMoveFamilyToSeverinManor (4F0036C9)].ARTH_RRF_PlayerAliasScript.OnPlayerLoadGame() - "ARTH_RRF_PlayerAliasScript.psc" Line 7

Probably the most common type of "error" you're going to see in the log. This isn't actually an error at all. It's a generic message spit out by one of the vanilla game functions that's used to check for the presence of other mods in your game. It just means that the mod it says doesn't exist is not being loaded right now. Ignore these.

Errors While Playing
 

Error: Unable to call RegisterForSingleUpdate - no native object bound to the script object, or object is of incorrect type
stack:
      [None].dht_IAFMonitorScript.RegisterForSingleUpdate() - "<native>" Line ?
      [None].dht_IAFMonitorScript.OnEffectStart() - "dht_IAFMonitorScript.psc" Line 16

There is largely nothing that can be done about errors of this type. When a magic effect is ready to expire, the Papyrus VM will aggressively destroy the instance of the script. It will generate errors like this if the script had an event pending before this happened. Ignore these unless you know for certain what's causing it.
 

[12/17/2014 - 11:59:16AM] Error: Cannot call IsInFaction() on a None object, aborting function call
stack:
        [alias Soldier1000001001000000001 on quest CWOBAQuest (8303B24F)].CWOBAScript2.OnInit() - "CWOBAScript2.psc" Line 17
[12/17/2014 - 11:59:16AM] Warning: Assigning None to a non-object variable named "::temp1"
stack:
        [alias Soldier1000001001000000001 on quest CWOBAQuest (8303B24F)].CWOBAScript2.OnInit() - "CWOBAScript2.psc" Line 17

This usually means that a property located in an ESP has not been filled in properly, leaving it empty, which in Papyrus is called "None". There are numerous things that require valid data to be processed that can throw this error, and the specific text for "None" errors will vary widely. It should be easy for a mod's author to fix, but generally requires a new game before such a fix would take effect due to the data already being baked into the save. It's also possible that the script simply isn't validating to make sure the property it's using has something in it. The second part where it mentions assigning None to a non-object variable will always accompany the original error in the call stack if something was trying to be assigned from the results.
 

[11/02/2014 - 02:48:09PM] Error: Cannot call SetValue() on a None object, aborting function call
stack:
        [_DE_Main_1_6 (88015CAE)]._de_epmonitor_1_6.MainLoop() - "_de_epmonitor_1_6.psc" Line 567
        [_DE_Main_1_6 (88015CAE)]._de_epmonitor_1_6.OnUpdate() - "_de_epmonitor_1_6.psc" Line 470

While this is basically the same as the above, it's important to notice that the originating function is an OnUpdate(). If you have logs where these show up repeatedly and fill them up, you will quickly find the game lagging and probably run into CTDs eventually. These OnUpdate() errors are known as "invalid registrations" and 999 times out of 1000 they are caused by people who disregard the advice not to uninstall mods on an active save. The ClearInvalidRegistrations setting in SKSE's ini file will correct these, but ONLY if they are from mods which no longer exist. That 1000th case is from a genuinely bad script. If it happens to be a vanilla script, there is nothing that can be done to correct it for that save. It is corrupt and beyond repair. Papyrus best practices dictate that mod authors use RegisterForSingleUpdate() for these types of scripts as it will limit the damage that is done if someone does something stupid.
 

[02/25/2015 - 03:14:28PM] Error: Property GlenmorilCovenAlias on script USKPRetroactive210Script attached to USKPRetroactive210 (020058C7) cannot be bound because <NULL alias> (54) on <NULL quest> (0004B2D9) is not the right type
[02/25/2015 - 03:14:28PM] Error: Property DriftshadeSanctuaryAlias on script USKPRetroactive210Script attached to USKPRetroactive210 (020058C7) cannot be bound because <NULL alias> (53) on <NULL quest> (0004B2D9) is not the right type
[02/25/2015 - 03:14:29PM] Error: Property DriftshadeSanctuaryAlias on script USKP_QF_ChangeLocation16_0300489C attached to USKPChangeLocation16 (0200489C) cannot be bound because <NULL alias> (53) on <NULL quest> (0004B2D9) is not the right type

This is an indication that there are properties on one quest which are linked back to another (in this case, USKP retro update scripts pointing to quest C00) where the quest record has been overridden by another mod and is blocking the "NULL Alias". The conflicting mod will either require a patch, or should include the missing data where possible. If this type of error happens entirely within a mod and DOES NOT conflict, then it means there are properties linked to aliases that have been deleted from a quest without the author properly cleaning up the remains.
 

[12/06/2014 - 12:48:49AM] error: weroad08 (001065F4): attempting to start event scoped quest outside of story manager.
stack:
[weroad08 (001065F4)].wescript.SetCurrentStageID() - "<native>" Line ?
[weroad08 (001065F4)].wescript.SetStage() - "Quest.psc" Line 124
[Item 2 in container (00000014)].WERoad08LetterScript.OnRead() - "WERoad08LetterScript.psc" Line 8

This kind of error comes up when a quest controlled by the Story Manager is trying to be started outside of the Story Manager. If you have a quest managed by the SM, then ONLY the SM can start it. There are several known instances of this error coming up that suggest a failed quest but later turn out to just be a false alarm so errors of this nature are not 100% guaranteed to be a legitimate problem.
 

[09/04/2014 - 12:46:21AM] error:  (000BA1DD): cannot start scene because its parent quest was not running.
stack:
    [ (000BA1DD)].SF_WEDL07Scene_000BA1DD.start() - "<native>" Line ?
    [WEDL07 (000B91E3)].QF_WEDL07_000B91E3.Fragment_7() - "QF_WEDL07_000B91E3.psc" Line 86

Similar to the above, but with scenes instead of managed quests. A scene cannot execute if the quest it is stored in is not running. There are confirmed instances where the error is proven to be false so unless these come up consistently, you can probably ignore them. The example used here is one such instance where the quest is obviously running yet the scene claims it isn't.
 

[10/26/2014 - 02:10:18PM] error:  (000C275C): cannot find variable named fPotemaFightVar.
stack:
    [ (000C275C)].ObjectReference.SetAnimationVariableFloat() - "<native>" Line ?
    [ (00103491)].dunPotemasMS06BossFightDummy.OnLoad() - "dunPotemasMS06BossFightDummy.psc" Line 109

Usually limited to scripts that handle animations. It indicates that the behavior files in control of what's being called don't have a variable that matches up with what the script thinks should be there. There are known instances where this is a false error and the script actually does exactly what it should be doing.
 

[02/26/2014 - 09:29:52AM] error:  (03002B74): Actor did not have a valid Animation Graph Manager.
stack:
[ (03002B74)].DLC1SeranaLevelingScript.SetSubGraphFloatVariable() - "<native>" Line ?
[Active effect 1 on  (03002B74)].DLC1_ReflectShieldSCRIPT.OnUpdate() - "DLC1_ReflectShieldSCRIPT.psc" Line 39

Currently it's not entirely known why these can occur. Generally speaking there should be no possibility for a loaded 3D actor to NOT have a valid animation graph, yet this error suggests otherwise.
 

[02/17/2014 - 11:40:26PM] error:  (0701FA3F): has no 3d, and so cannot have its motion type changed.
stack:
    [ (0701FA3F)].trapsoulgemcontroller.SetMotionType() - "<native>" Line ?
    [ (0701FA3F)].trapsoulgemcontroller.onBeginState() - "trapSoulGemController.psc" Line 37
    [ (0701FA3F)].trapsoulgemcontroller.GotoState() - "Form.psc" Line ?
    [ (0701FA3E)].MagicTrap.testRefIsSoulGem() - "MagicTrap.psc" Line 261
    [ (0701FA3E)].MagicTrap.CellAttachSetUp() - "MagicTrap.psc" Line 365
    [ (0701FA3E)].MagicTrap.OnLoad() - "MagicTrap.psc" Line 206

Errors related to 3D Havok states. These usually crop up with references that are no longer loaded in memory. It is believed to be a false error as returning to an object that generates one of these will show it to be in the correct state. Confirmed to be a false error when it occurs in an OnLoad() block because those only get run after the 3D data is loaded.
 

[12/05/2013 - 08:53:35PM] error: Failed to setup moving reference because it has no parent cell or no 3D
stack:
    [ (0501EAB5)].DLC2DBBookLevelLightTranslationSCRIPT.TranslateTo() - "<native>" Line ?
    [ (0501EAB5)].DLC2DBBookLevelLightTranslationSCRIPT.TranslateToRef() - "ObjectReference.psc" Line 583
    [ (0501EAB5)].DLC2DBBookLevelLightTranslationSCRIPT.DoLightMovement() - "DLC2DBBookLevelLightTranslationSCRIPT.psc" Line 72
    [ (0501EAB5)].DLC2DBBookLevelLightTranslationSCRIPT.HandleTransitionEnd() - "DLC2DBBookLevelLightTranslationSCRIPT.psc" Line 147
    [ (0501EAB5)].DLC2DBBookLevelLightTranslationSCRIPT.OnTranslationAlmostComplete() - "DLC2DBBookLevelLightTranslationSCRIPT.psc" Line 92

Possibly related to the above. Seems to get thrown when a 3D object is pushed out of the loaded range of cells before the script finishes, but this hasn't been confirmed.
 

[11/23/2013 - 11:41:23PM] error: Object reference has no 3D
stack:
[ (03013835)].Sound.Play() - "<native>" Line ?
[ (FF000908)].dunWEFXBatActivator.OnActivate() - "dunWEFXBatActivator.psc" Line 12

Another error that should only be generated when an object is not loaded. It has been confirmed to occur even on objects that ARE loaded though so it's not entirely obvious what the script is expecting.
 

[09/11/2013 - 09:25:13PM] error:  (FF0008E5): Failed to send event HeadBleed04 for unspecified reasons.
stack:
    [ (FF0008E5)].MGRitual05DragonScript.PlaySubGraphAnimation() - "<native>" Line ?
    [Active effect 1 on  (FF0008E5)].FXDragonBloodDamageScript.OnHit() - "FXDragonBloodDamageScript.psc" Line 343

The ultimate in stupid error messages. It obviously cannot be solved without knowing what the unspecified reasons are.

Other Errors You May See
 

[12/17/2014 - 11:59:16AM] [_DS_HB_MCM <_DS_HunterbornMCM (C0001D89)>] ERROR: Cannot add option $_DS_HB_Skeevers outside of OnPageReset()

Errors that look like this are almost always going to be specific to mods with MCM options. It's an error message generated by the SkyUI libraries when the mod is doing something wrong with them. It is *NOT* a fault in SkyUI itself. These errors need to be reported to the author of the mod rather than to the SkyUI team.
 

[02/24/2015 - 10:29:56PM] VM is freezing...
[02/24/2015 - 10:29:56PM] VM is frozen
[02/24/2015 - 10:29:57PM] Saving game...
[02/24/2015 - 10:29:58PM] VM is thawing...

A totally routine set of messages. Ignore them. They merely tell you the Papyrus VM has halted to allow you to save (or load) the game. They don't mean the game engine froze up and stopped responding as SOME sites have erroneously reported.
 

[12/17/2014 - 12:14:05PM] Warning: Script profiling is disabled - profiling request ignored
stack:
        <unknown self>.Debug.StartScriptProfiling() - "<native>" Line ?
        [ (CB001844)].GetShelterTBScript.OnTriggerEnter() - "GetShelterTBScript.psc" Line 37

Pretty much exactly what it says. You hit some kind of trigger that wants to run profiling but Papyrus profiling is disabled. This is generally not something you'll find while playing as it's only supposed to be something mod authors use for diagnostics.

  • Like 3
Link to comment
Share on other sites

Some of these findings might go over to the wiki.

We initiates had trouble with this error from the tutorial, however there's still hope for the future?

Edit:

Gotta couple more:

[02/27/2015 - 04:45:30AM] error: Received a latent return for stack 79, but stack is no longer running - ignoring.

what happend to the poor old stack?

[02/27/2015 - 04:42:46AM] Error: Object handle 0x3EEFF040 is missing from the object table - variable value will be cleared

This happens after clearing form data from the save

[02/27/2015 - 04:42:46AM] Errors occurred while loading the Papyrus save game data

Ditto

 

Edit:

 

Here's another one unique to a damaged? save: :(

[04/09/2015 - 12:32:22AM] Error: Cannot add None to a container
stack:
[ (00000014)].Actor.AddItem() - "<native>" Line ?
[topic info 000D0696 on quest t02 (000211D5)].TIF__000D0696.Fragment_0() - "TIF__000D0696.psc" Line ?
[04/09/2015 - 12:38:17AM] Error: Cannot add None to a container
stack:
[ (00000014)].Actor.AddItem() - "<native>" Line ?
[topic info 00026ECF on quest t02 (000211D5)].TIF__00026ECF.Fragment_0() - "TIF__00026ECF.psc" Line ?

Happens in the Book of Love quest when Yngvar sells his poem to Player, and later, Faleen hands over a LoveLetter to be passed onto Calcelmo. The quest progresses but Player never receives the poem nor the letter. In the light of this post, starting a new game would be a workaround.

Link to comment
Share on other sites

Really helpful information, thanks.

Want to mention that TES5Edit has papyrus log analyzer that allows to browse messages related to particular FormIDs, accessible from right click -> Other -> Log Analyzer -> Papyrus Log.

Double click will position on that record to check what mods override it and could be the source of issues.

 

HhruNMe.png

  • Like 2
Link to comment
Share on other sites

Wow this is nice, wish I had this when I was analyzing my Papyrus logs from my 100% completion run. Next time :P

Link to comment
Share on other sites

  • 8 months later...

Another interesting utility : Papyrus Log Viewer by sialivi. Last version released on November 24, 2015.

 

From the description page :

 

This simple log viewer will only show each entry once, making it easier to get an overview and less likely to miss less common entries among all the duplicates.

 

Link to comment
Share on other sites

  • 4 months later...
[09/11/2013 - 09:25:13PM] error:  (FF0008E5): Failed to send event HeadBleed04 for unspecified reasons.

stack:

    [ (FF0008E5)].MGRitual05DragonScript.PlaySubGraphAnimation() - "<native>" Line ?

    [Active effect 1 on  (FF0008E5)].FXDragonBloodDamageScript.OnHit() - "FXDragonBloodDamageScript.psc" Line 343

The ultimate in stupid error messages. It obviously cannot be solved without knowing what the unspecified reasons are.

 

The reference does not exist anymore, therefore the event can not apply the function anymore. This often happens when too many events gets registered on an object.

The script code should queue (block) and (batch) handle these events better. It should stop trying to process OnUpdate when the ObjectRef is out of scope.   

Link to comment
Share on other sites

The error is "Unspecified reasons" Wonder what the others might be.

A possible candidate is that other mods might also have RegisterForSingleUpdate  for the reference, but the timeslice is too small. Or perhaps the object is not within scope parameters or predefined radius.

Because it's likely to occur in situations where logging is known to compromise performance, error verbosity is kept to a minimum by the processor.

Hence the stoopid message.

Link to comment
Share on other sites

  • 2 months later...

I would like to add some information on animation-related log errors here. Examples will be from Fallout 4, but the functionality is present in Skyrim too (and the errors in question are known from Skyrim papyrus logs as well), so this shouldn't make a big difference.

 

 

The first one is about animation graph variables:

[06/10/2016 - 08:06:31PM] error:  (FF006D04): cannot find variable named fDampRate.
stack:
    [ (FF006D04)].BirdCritterScript.SetAnimationVariableFloat() - "<native>" Line ?
    [ (FF006D04)].BirdCritterScript.flyToTree() - "<unknown file>" Line ?
    [ (FF006D04)].BirdCritterScript.waiting.OnTimer() - "<unknown file>" Line ?

As one might expect, this indicates that the script is using a wrong name for the animation graph variable it was supposed to modify. Those variables are used to modify the speed at which certain components of an animation are played at run time. Their names are hardcoded in the .kf files, so this might be an obstacle when you try to fix the bug. For simplicity, let's assume that you decode the animation file and find out that the variable name is indeed wrong. Then you correct it in the script, compile it and continue playing - only to see much later that the error is still on your logs. WTF ?!?

 

Well ... it's a 3D issue. If an object's 3D is not loaded, the animation graph variables won't be found either (even if the correct names are used). Most likely, your script is checking for 3D in the wrong place. In other words, don't do this:

myObjectRef.SetAnimationVariableFloat("Name1", Float1)
myObjectRef.SetAnimationVariableFloat("Name2", Float2)

if Is3DLoaded()
	myObjectRef.playAnimation("AnimationName")
endif

Instead, do that:

if Is3DLoaded()
	myObjectRef.SetAnimationVariableFloat("Name1", Float1)
	myObjectRef.SetAnimationVariableFloat("Name2", Float2)
	myObjectRef.playAnimation("AnimationName")
endif
Link to comment
Share on other sites

The next one is tricky:

[06/06/2016 - 08:07:11AM] error:  (0003D6BE): model was not loaded when we tried to play an animation on it (most likely you're calling for animations in OnInit.).
stack:
    [ (0003D6BE)].Default2StateActivator.PlayAnimationAndWait() - "<native>" Line ?
    [ (0003D6BE)].Default2StateActivator.SetDefaultState() - "<unknown file>" Line ?
    [ (0003D6BE)].Default2StateActivator.OnReset() - "<unknown file>" Line ?
[06/06/2016 - 08:07:20AM] error:  (0003D6BE): the animation graph (SpecialCaseDoors) cannot currently process event "Close".
stack:
    [ (0003D6BE)].Default2StateActivator.PlayAnimationAndWait() - "<native>" Line ?
    [ (0003D6BE)].Default2StateActivator.SetDefaultState() - "<unknown file>" Line ?
    [ (0003D6BE)].Default2StateActivator.OnLoad() - "<unknown file>" Line ?

The vanilla version of Default2StateActivator script usually throws these two errors in a row. The first one is trivial: there is a 3D check missing in the OnReset() event. The second one is rather cryptic as it refuses to tell us why the heck it couldn't run the animation. That's the one I'm going to shed some light upon.

 

Let's have a look at part of the script (with the missing 3D check already added):

EVENT OnLoad()
	if (shouldSetDefaultState)
		SetDefaultState()
	EndIf
endEVENT

Event OnReset()
	;EDIT: Added 3D check
	if (shouldSetDefaultState) && WaitFor3DLoad()
		SetDefaultState()
	EndIf
EndEvent

;This has to be handled as a function, since OnLoad and OnReset can fire in either order, and we can't handle competing animation calls.
Function SetDefaultState()

	if (isOpen)
		playAnimationandWait(startOpenAnim, openEvent)

		if (InvertCollision == FALSE)
			trace(self + " Disabling Collision")
			DisableLinkChain(TwoStateCollisionKeyword)
		else
			trace(self + " Enabling Collision")
			EnableLinkChain(TwoStateCollisionKeyword)
		endif

		myState = 0
	Else
		playAnimationandWait(closeAnim, closeEvent)
		
		if (InvertCollision == FALSE)
			trace(self + " Enabling Collision")
			EnableLinkChain(TwoStateCollisionKeyword)
		else
			trace(self + " Disabling Collision")
			DisableLinkChain(TwoStateCollisionKeyword)
		endif

		myState = 1
	EndIf
	
EndFunction

This script reacts to two events: OnLoad() and OnReset(). When an event fires, a thread is created for that event to run the specified code. When both events fire in short succession, we have two threads (one for either event) running on the same script. This is not an issue per se, but it becomes an issue here because both threads are calling the same function. With the 3D check in place, the chances for both threads running simultaneously have increased because OnReset now has to wait for 3D, so it will call the SetDefaultState() function almost at the same time as OnLoad, most likely within the same frame.

 

As a result, there will be two animation calls (one from either thread) on the same object within a short period of time, presumably within the same frame - and this is what causes the error: Only the first call gets through. While this is still processed, other calls cannot be handled and result in "cannot currently process event" type messages being thrown on the log.

 

Thus simply speaking, "The animation graph (ABC) cannot currently process event "XYZ" error indicates a threading issue !

 

(Note: I have no ultimate proof yet that this is the only issue that can cause this error. It is certainly one of the most frequent causes of this error though.)

 

To fix this, the SetDefaultState() function needs a thread lock:

EVENT OnLoad()
	if (shouldSetDefaultState)
		SetDefaultState()
	EndIf
endEVENT

Event OnReset()
	;EDIT: Added 3D check
	if (shouldSetDefaultState) && WaitFor3DLoad()
		SetDefaultState()
	EndIf
EndEvent

;EDIT: added lock bool
bool bSetupLock = false

;This has to be handled as a function, since OnLoad and OnReset can fire in either order, and we can't handle competing animation calls.
Function SetDefaultState()

	;EDIT: Added lock to handle competing calls from OnLoad and OnReset
	while bSetupLock
		utility.wait(0.1)
	endwhile
	bSetupLock = true

	if (isOpen)
		playAnimationandWait(startOpenAnim, openEvent)

		if (InvertCollision == FALSE)
			trace(self + " Disabling Collision")
			DisableLinkChain(TwoStateCollisionKeyword)
		else
			trace(self + " Enabling Collision")
			EnableLinkChain(TwoStateCollisionKeyword)
		endif

		myState = 0
	Else
		playAnimationandWait(closeAnim, closeEvent)
		
		if (InvertCollision == FALSE)
			trace(self + " Enabling Collision")
			EnableLinkChain(TwoStateCollisionKeyword)
		else
			trace(self + " Disabling Collision")
			DisableLinkChain(TwoStateCollisionKeyword)
		endif

		myState = 1
	EndIf
	
	;EDIT: release lock
	bSetupLock = false
	
EndFunction
Link to comment
Share on other sites

  • 4 weeks later...

After I decided to go for a "let's make my setup as clean as possible" session :

[07/09/2016 - 03:22:28PM] Error: Cannot cast from None to SKI_WidgetBase[]
stack:
	[iHUDControlQuest (08000805)].ihudwidgetscript.initialize() - "ihudwidgetscript.psc" Line 38
	[iHUDControlQuest (08000805)].ihudcontrolscript.startUp() - "ihudcontrolscript.psc" Line 93
	[iHUDMaintainanceQuest (08002853)].iHUDMaintainanceScript.startUp() - "ihudmaintainancescript.psc" Line 20
	[alias PlayerAlias on quest iHUDMaintainanceQuest (08002853)].iHUDLoadScript.OnInit() - "ihudloadscript.psc" Line 7

I spent a lot of time figuring out why iHUD is sending this error upon initialization.

 

Turn out the debug information have a small issue, the error is from line 40 and not 38 :

38.    SKI_WidgetBase[] widgets = skiWidgetManager.GetWidgets()
39.    			
40.    if (widgets == none)
41.       return
42.    endif

The error is in the if condition. While this structure is the regular one to check for a forms existence after fetching it in papyrus, this doesn't work for array. since "widgets" is an array and not a form, the condition "if (widgets == none)" - or its short version "if (!widgets)" - is invalid, the whole if block is skipped, and the error mentioned above is logged.

 

If you want to get rid of the annoying error from iHUD in your log, you can just remove those 3 lines from the script and recompile it (you'll need the unofficial skyUI sdk for the widgets scripts sources), they useless anyway. The error it's supposed to prevent cannot occur anyway, since the existence of skiWidgetManager is already checked right before this section, and the GetWidgets() function called cannot fail (worst case is that it'd send an array of 128 empty widgets, but this array always exist).

 

 

 

Side note :

iHUD have an other error, in the plugin, its maintenance quest doesn't have its "run once" flag checked, meaning this initialisation is run twice upon 1st initialization, so you actually see this error in the log twice when starting a new game. Just open iHUD in the CK and go check this flag to remove the useless initialization sequence.

 

 

tl;dr :

Arrays cannot be checked against "None" to see if they exist or not. If you try, an invalid cast exception is thrown and catched by the papyrus engine (and logged) as "Cannot cast from None to Something[]" 

Link to comment
Share on other sites

After I decided to go for a "let's make my setup as clean as possible" session :

 

tl;dr :

Arrays cannot be checked against "None" to see if they exist or not. If you try, an invalid cast exception is thrown and catched by the papyrus engine (and logged) as "Cannot cast from None to Something[]" 

 

That's another remarkable difference to Fallout 4 scripting.

Link to comment
Share on other sites

zilav

 

I didn't know the Papyrus Log viewer in TES5Edit even existed and yet there it was just in front without knowing it existed.

 

I find that feature to be very useful and I'll try to remember that in the future, especially now since I've had started to use Hadoram's Save Script Cleaner.

 

Looking at a specific mod then view what scripts that belongs to that mod in TES5Edit's Papryus Log viewer will definitely save me some time, instead of looking at every script that the Save Cleaner have listed based on one of my gamesave(s).

Link to comment
Share on other sites

  • 1 year later...

Not sure this is actually an error but could someone help me understand what this means?

While I let my game run on vanity camera in a cleared interior cell (Drelas Cottage) to let SKSE "ClearInvalidRegistrations" do its job, my Papyrus log filled up with this line some 2500 times in 4 hours - and with only that line, nothing else:

[03/04/2018 - 07:50:43PM] [DLC2PillarBuilderActorScript < (020177DB)>]OnPackageStart()

Reference of the actor varied - 20 different actors in fact - although (020177DB) is the most common one. I can't figure out what's going on, this points at the Dragonborn main quest which I completed ages ago (I only have Dragonborn installed on that machine). No stack above it, no error, just this line filling in every 2 or 3 seconds. I have absolutely no other mod referencing these actors, quest, packages or locations.

I did a bit of digging in SKSE and the CK but it's a fairly complex quest and I'm not sure I get it all. Not sure either that the mentioned script "DLC2PillarBuilderActorScript" is the culprit - looks more like some other script is trying to force update the quest aliases.

Has anybody else seen that before? Any idea what I should do to clean that mess up? Thanks a bunch!

Link to comment
Share on other sites

I think if you just let the player on idles, the game turns on abAIDriven

Quote

Function SetPlayerAIDriven(bool abAIDriven = true) native global

which persists in calling OnPackageStart.

Also try debugging this in DLC2PillarScript by removing the semicolons:

Quote

Function CheckMyPillarToggle(Actor ActorToCheck)
    ObjectReference myPillarToggleLink = ActorToCheck.GetLinkedRef(DLC2LinkPillarToggle)

;    Debug.Trace(self + "CheckMyPillarToggle()" + ActorToCheck)

    if myPillarToggleLink == NONE
;         Debug.Trace(self + "CheckMyPillarToggle() ERROR: myPillarToggleLink == NONE, so bailing out early with RETURN "  + ActorToCheck, 2)
        RETURN

    else
        if myPillarToggleLink.IsDisabled()
;            Debug.Trace(self + "CheckMyPillarToggle() myPillarToggleLink isDisabled() == true, so REMOVING me from DLC2PillarBuilderFaction faction. "  + ActorToCheck)
            ActorToCheck.RemoveFromFaction(DLC2PillarBuilderFaction)

        else
;            Debug.Trace(self + "CheckMyPillarToggle() myPillarToggleLink isDisabled() == false, so NOT removing me from DLC2PillarBuilderFaction faction. "  + ActorToCheck)

        endif

    endif
EndFunction

Recompile and run the game to see if there's any difference in the log output.

Link to comment
Share on other sites

It's a harmless debug message. Which indicates you aren't using the unofficial patch - we suppressed all of those.

Link to comment
Share on other sites

Oh, sorry, I missed your replies, guys - and thanks for it! :)

Nope, not using any unofficial patch on this install, it's as ancient as Skyrim itself, only one DLC, heavily modded, still running smoothly and I was reluctant to patch it after several 1000 hours on it - I use it mostly as a crash test for my mods. (I do have another full install on another computer). It didn't look like an error but it sure bloats my logs when I use them for debugging my mods.

Thanks for the tip anyway, I'll try that Imstearn, see what difference it makes in the log.

Link to comment
Share on other sites

  • 2 weeks later...

I've been getting random CTD's in Skyrim SE every 15 minutes or so when walking in the Skyrim wilderness, I've got quite the heavy load order sorted by LOOT. I checked the papyrus log (the 3 most recent ones where a crash has occured) and the last few lines before my game kicks the bucket are something in the lines with this script:

Quote

n() - "Actor.psc" Line 570
    [Active effect 2 on  (000846CD)].VoiceCharmFactionScript.OnEffectStart() - "VoiceCharmFactionScript.psc" Line 7
[03/16/2018 - 03:05:09PM] error: Cannot set the faction rank with a None faction
stack:
    [ (000846CD)].lvlpredatorscript.SetFactionRank() - "<native>" Line ?
    [ (000846CD)].lvlpredatorscript.AddToFaction() - "Actor.psc" Line 570
    [Active effect 1 on  (000846CD)].VoiceCharmFactionScript.OnEffectStart() - "VoiceCharmFactionScript.psc" Line 7
[03/16/2018 - 03:05:11PM] error: Cannot set the faction rank with a None faction
stack:
    [ (000846CD)].lvlpredatorscript.SetFactionRank() - "<native>" Line ?
    [ (000846CD)].lvlpredatorscript.AddToFaction() - "Actor.psc" Line 570
    [Active effect 2 on  (000846CD)].VoiceCharmFactionScript.OnEffectStart() - "VoiceCharmFactionScript.psc" Line 7
[03/16/2018 - 03:05:24PM] error: Cannot set the faction rank with a None faction
stack:
    [ (000846CD)].lvlpredatorscript.SetFactionRank() - "<native>" Line ?
    [ (000846CD)].lvlpredatorscript.AddToFaction() - "Actor.psc" Line 570
    [Active effect 1 on  (000846CD)].VoiceCharmFactionScript.OnEffectStart() - "VoiceCharmFactionScript.psc" Line 7
[03/16/2018 - 03:05:26PM] error: Cannot set the faction rank with a None faction
stack:
    [ (000846CD)].lvlpredatorscript.SetFactionRank() - "<native>" Line ?
    [ (000846CD)].lvlpredatorscript.AddToFaction() - "Actor.psc" Line 570
    [Active effect 2 on  (000846CD)].VoiceCharmFactionScript.OnEffectStart() - "VoiceCharmFactionScript.psc" Line 7
[03/16/2018 - 03:05:28PM] error: Cannot set the faction rank with a None faction
stack:
    [ (000846CD)].lvlpredatorscript.SetFactionRank() - "<native>" Line ?
    [ (000846CD)].lvlpredatorscript.AddToFaction() - "Actor.psc" Line 570
    [Active effect 1 on  (000846CD)].VoiceCharmFactionScript.OnEffectStart() - "VoiceCharmFactionScript.psc" Line 7
[03/16/2018 - 03:05:30PM] error: Cannot set the faction rank with a None faction
stack:
    [ (000846CD)].lvlpredatorscript.SetFactionRank() - "<native>" Line ?
    [ (000846CD)].lvlpredatorscript.AddToFaction() - "Actor.psc" Line 570
    [Active effect 2 on  (000846CD)].VoiceCharmFactionScript.OnEffectStart() - "VoiceCharmFactionScript.psc" Line 7
[03/16/2018 - 03:05:30PM] error: Cannot set the faction rank with a None faction
stack:
    [ (6C02E955)].Actor.SetFactionRank() - "<native>" Line ?
    [ (6C02E955)].Actor.AddToFaction() - "Actor.psc" Line 570
    [Active effect 6 on  (6C02E955)].VoiceCharmFactionScript.OnEffectStart() - "VoiceCharmFactionScript.psc" Line 7
[03/16/2018 - 03:05:32PM] error: Cannot set the faction rank with a None faction
stack:
    [ (000846CD)].lvlpredatorscript.SetFactionRank() - "<native>" Line ?
    [ (000846CD)].lvlpredatorscript.AddToFaction() - "Actor.psc" Line 570
    [Active effect 1 on  (000846CD)].VoiceCharmFactionScript.OnEffectStart() - "VoiceCharmFactionScript.psc" Line 7
[03/16/2018 - 03:05:32PM] error: Cannot set the faction rank with a None faction
stack:
    [ (6C02E955)].Actor.SetFactionRank() - "<native>" Line ?
    [ (6C02E955)].Actor.AddToFaction() - "Actor.psc" Line 570
    [Active effect 5 on  (6C02E955)].VoiceCharmFactionScript.OnEffectStart() - "VoiceCharmFactionScript.psc" Line 7
[03/16/2018 - 03:05:34PM] error: Cannot set the faction rank with a None faction
stack:
    [ (000846CD)].lvlpredatorscript.SetFactionRank() - "<native>" Line ?
    [ (000846CD)].lvlpredatorscript.AddToFaction() - "Actor.psc" Line 570
    [Active effect 2 on  (000846CD)].VoiceCharmFactionScript.OnEffectStart() - "VoiceCharmFactionScript.psc" Line 7
[03/16/2018 - 03:05:46PM] error: Cannot set the faction rank with a None faction
stack:
    [ (000846CD)].lvlpredatorscript.SetFactionRank() - "<native>" Line ?
    [ (000846CD)].lvlpredatorscript.AddToFaction() - "Actor.psc" Line 570
    [Active effect 1 on  (000846CD)].VoiceCharmFactionScript.OnEffectStart() - "VoiceCharmFactionScript.psc" Line 7
[03/16/2018 - 03:05:50PM] error: Cannot set the faction rank with a None faction
stack:
    [ (000846CD)].lvlpredatorscript.SetFactionRank() - "<native>" Line ?
    [ (000846CD)].lvlpredatorscript.AddToFaction() - "Actor.psc" Line 570
    [Active effect 2 on  (000846CD)].VoiceCharmFactionScript.OnEffectStart() - "VoiceCharmFactionScript.psc" Line 7
 

Is this the script that makes my game crash? I've tried searching my mod files and it doesn't seem like any of my mods had this script included in their package. How can I find out which mods use this script? Sorry for asking help but I've tried modding Skyrim for quite some time but it never really seems to work for me. Thanks in advance

Link to comment
Share on other sites

No. Anything that shows up in the Papyrus log was already processed by the engine. The log is useless for trying to track down a CTD.

VoiceCharmFactionScript is used by the vanilla game. This suggests that something has made a change to the magic effect it's attached to which has blanked the faction property it's looking for. It's annoying log spam which indicates a bug of some sort, but harmless beyond that.

Link to comment
Share on other sites

  • 10 months later...

Create an account or sign in to comment

You need to be a member in order to leave a comment

Create an account

Sign up for a new account in our community. It's easy!

Register a new account

Sign in

Already have an account? Sign in here.

Sign In Now
×
×
  • Create New...