ObjectReference Broken Pointer Bug

Introduction

These are my (taleden's) logs and notes regarding the ObjectReference broken pointer bug, whose symptom is the log error "no native object bound to the script object, or object is of incorrect type". On 2013-10-25 I posted the following to Bethesda's CreationKit forum:

The folks at the Unofficial Skyrim Patch (and probably lots of other modders) have been struggling for months with ObjectReference pointers that go bad, and I think it may actually be a bug in the Papyrus scripting engine, or the game engine, or maybe in the interface between the two.

The symptom of this bug is an error in the debug log that reads "Unable to call [Method] - no native object bound to the script object, or object is of incorrect type". This happens even when the pointer on which the method is being called is not None; when that is the case, the error instead says "Cannot call [Method] on a None object, aborting function call".

I believe the bug arises whenever an object reference has an extra script attached to it (extending the ObjectReference script), and that item is moved from a container/inventory into the world, while it also has a persistent reference.

Here's a short example that illustrates the problem:

Form item = Game.GetForm(0x10AA19) ; Silver Sword
ObjectReference ref = Game.GetPlayer().PlaceAtMe(item)
Debug.Trace(ref+" GetFormID()="+ref.GetFormID()+", SilverPerk="+(ref as SilverSwordScript).SilverPerk)
Game.GetPlayer().AddItem(ref)
Debug.Trace(ref+" GetFormID()="+ref.GetFormID()+", SilverPerk="+(ref as SilverSwordScript).SilverPerk)
ref = Game.GetPlayer().DropObject(item)
Debug.Trace(ref+" GetFormID()="+ref.GetFormID()+", SilverPerk="+(ref as SilverSwordScript).SilverPerk) ; line 33

The log then reads:

[10/25/2013 - 02:10:58PM] [SilverSwordScript < (FF000898)>] GetFormID()=-16775016, SilverPerk=[Perk < (0010D685)>] [10/25/2013 - 02:10:58PM] [SilverSwordScript <Item 3 in container (00000014)>] GetFormID()=-16775016, SilverPerk=[Perk < (0010D685)>] [10/25/2013 - 02:10:58PM] error: Unable to call GetFormID - no native object bound to the script object, or object is of incorrect type stack: [Item 3 in container (00000014)].SilverSwordScript.GetFormID() - "<native>" Line ? [alias PlayerRef on quest TestQuest (0A000D6A)].TestQuest_PlayerRef_Script.OnUpdate() - "TestQuest_PlayerRef_Script.psc" Line 33 [10/25/2013 - 02:10:58PM] warning: Assigning None to a non-object variable named "::temp6" stack: [alias PlayerRef on quest TestQuest (0A000D6A)].TestQuest_PlayerRef_Script.OnUpdate() - "TestQuest_PlayerRef_Script.psc" Line 33 [10/25/2013 - 02:10:58PM] [SilverSwordScript <Item 3 in container (00000014)>] GetFormID()=0, SilverPerk=[Perk < (0010D685)>]

Note that the item must have a script either on its base form (as the Silver Sword does here) or on the particular cell-placed reference that the player picks up (such as Ghostblade and Zephyr), and the reference must be persistent at the moment it is dropped back into the world (as is done here by having the PlaceAtMe()-created reference stored in a running script variable at the time DropObject() is called; PlaceAtMe() can also force the created reference to be persistent, but the result is the same in this test).

When these conditions are met, then any ObjectReference pointer which refers to the item is prone to break, as seen here in the pointer returned from DropObject(). When a pointer breaks in this way, then no native methods can be called on it (such as GetFormID()), however methods which are fully defined in Papyrus on the attached script or any of its parent scripts can still be called normally (such as the implicit SilverPerk property getter function). This implies that the Papyrus script object is no longer correctly linked to its corresponding game engine object, so when it tries to call into the game engine to evaluate a native method, the engine reports that it has no (compatible) object to run it on.

Note that the bug is not limited to DropObject(), that's just the quickest way to invoke it. For example, the player can drop the item manually, and any (persistent) ObjectReference pointer which was previously received and cached in OnItemAdded(), OnItemEquipped() etc. will immediately become broken. Or, the player can drop the item while it is equipped, and then OnItemUnequipped() receives a broken pointer, but OnItemRemoved() receives a functional pointer. The key elements are the persistent object reference, and the extra attached script.

I have a lot more log data if anyone is interested, plus an object reference testing mod that I've been using to diagnose this issue. Apologies also if this has been reported and discussed before, I did a search and only found other players with the same log error, but no investigation or explanation.

This article contains the log data mentioned above.

Testing Methodology

In order to understand these logs, here is the testing methodology that I used to generate them.

I made a testing mod which uses a quest's reference alias on the player to monitor item-related events and analyze the object reference pointers they each receive from the engine. To keep the test cases as clean as possible, the mod also defines six custom items which are all clones of the Iron Sword, with some variation to mimic a particular test case:

• Test Sword (NP, NS)
• Test Sword (NP, FS)
• Test Sword (P, NS)
• Test Sword (P, FS)
• Test Sword (P, AS)
• Test Sword (P, RS)

The tags on each item identify the properties of each test case:

• "NP" means non-persistent, so these two items are given to the player on game load using AddItem() so that they do not have a persistent reference.
• The "P" items (except for "P, RS") are granted by the test quest as created reference aliases so that they are persistent.
• "NS" means non-scripted, so these forms have no extra scripts attached anywhere.
• "FS" means form-scripted, so these base weapon forms have scripts attached which extend ObjectReference.
• "AS" means alias-scripted, so the quest reference alias which creates this item also attaches a script which extends ReferenceAlias.
• The "P, RS" item is placed directly in the qasmoke cell so that it has a persistent world-placed reference, and so that a script can be attached to that placed reference in the CK.

There is no "NP, RS" test case because I don't think it's possible to attach a script via reference without that reference also being persistent (i.e. placed in a cell in the CK). Likewise for "NP, AS", as soon as a quest fills a reference into an alias in order to put an alias script on it, my understanding is that the reference also becomes persistent.

The mod also has a menu control item, and the first time this is activated, the player alias script starts listening for item events (OnItemAdded(), OnItemRemoved(), OnObjectEquipped() and OnObjectUnequipped()). The first time one of these events fires, the base form involved (which should be one of the test items above) is set as the form to be tracked, so that future events are only handled if they involve the same base item. The ObjectReference pointers provided to each event handler are then cached in six different slots, corresponding to six ways they can be acquired:

• "AW": OnItemAdded() from the world (akSrcContainer == None)
• "RW": OnItemRemoved() to the world (akDestContainer == None)
• "AC": OnItemAdded() from a container (akSrcContainer != None)
• "RC": OnItemRemoved() to a container (akDestContainer != None)
• "Eq": OnObjectEquipped()
• "Un": OnObjectUnequipped()

Each cached pointer is filled in the first time each event fires and receives an ObjectReference pointer other than None. On each event, a log message is written that reports the properties of the ObjectReference pointer received by the event: if it is broken (so not even GetFormID() can be called on it without error), the log just shows "(broken)"; otherwise, the log prints the ObjectReference's own FormID, the FormIDs returned by GetBaseObject() and GetParentCell(), and the flags returned by Is3DLoaded() and IsDeleted(). This is followed by the pointer itself cast as a string (which reveals what script Papyrus thinks it represents) and a list of flags indicating whether the pointer compares as equal to any of the previously observed and cached ObjectReference pointers, or whether the received pointer was stored in any of those slots.

Meanwhile, a 10s OnUpdate() loop periodically tests each cached ObjectReference pointer and reports "-" if it is still set to None, "+" if it is set and remains functional (i.e. GetFormID() can be called without the "object is of incorrect type" error), or "!" if it has become broken (GetFormID() appears to return 0, which corresponds with the log error).

Once a form is being tracked, the menu item can also be used to call Player.DropObject(), Player.AddItem(), ref.MoveTo() and ref.Reset(), using the base form or any of the cached ObjectReferences. When calling DropObject(), the return value is also reported and compared to the cached ObjectReference pointers.

Test cases

non-persistent, non-scripted

The log begins while the test item is in inventory but not equipped:

[10/22/2013 - 03:10:58PM] ready to track references
[10/22/2013 - 03:11:03PM] now tracking Test Sword (NP, NS) '[WEAPON < (0A000D62)>]'
[10/22/2013 - 03:11:03PM] OnItemAdded(world): [None]
[10/22/2013 - 03:11:10PM] OnObjectEquipped(): [None]
[10/22/2013 - 03:11:13PM] OnObjectUnequipped(): [None]
[10/22/2013 - 03:11:15PM] OnUpdate(): AW:- RW:- AC:- RC:- Eq:- Un:-
[10/22/2013 - 03:11:19PM] OnItemRemoved(Container): [None]
[10/22/2013 - 03:11:26PM] OnItemAdded(Container): [None]
[10/22/2013 - 03:11:32PM] OnItemRemoved(world): FF000898 (base=A000D62 cell=32Ae7 3d=1 del=0) '[ObjectReference < (FF000898)>]' ->RW

At first, since the item does not have a persistent reference, the event handlers are not given any ObjectReference pointer at all; this is expected according to the CK documentation. But as also noted in the CK wiki, OnItemRemoved() is different: "If a non-persistent item is dropped from inventory into the world the generated reference is received." Since this pointer is immediately cached in a script variable by the test mod, the reference becomes persistent and now all the other events start receiving it as well:

[10/22/2013 - 03:11:37PM] OnItemAdded(world): FF000898 (base=A000D62 cell=32Ae7 3d=0 del=1) '[ObjectReference < (FF000898)>]' ->AW ==RW
[10/22/2013 - 03:11:42PM] OnUpdate(): AW:+ RW:+ AC:- RC:- Eq:- Un:-
[10/22/2013 - 03:11:52PM] OnObjectEquipped(): FF000898 (base=A000D62 cell=32Ae7 3d=0 del=1) '[ObjectReference < (FF000898)>]' ==AW ==RW ->Eq
[10/22/2013 - 03:11:59PM] OnObjectUnequipped(): FF000898 (base=A000D62 cell=32Ae7 3d=0 del=1) '[ObjectReference < (FF000898)>]' ==AW ==RW ==Eq ->Un
[10/22/2013 - 03:12:06PM] OnItemRemoved(world): FF000898 (base=A000D62 cell=32Ae7 3d=1 del=0) '[ObjectReference < (FF000898)>]' ==AW ==RW ==Eq ==Un
[10/22/2013 - 03:12:11PM] OnUpdate(): AW:+ RW:+ AC:- RC:- Eq:+ Un:+
[10/22/2013 - 03:12:13PM] OnItemAdded(world): FF000898 (base=A000D62 cell=32Ae7 3d=0 del=1) '[ObjectReference < (FF000898)>]' ==AW ==RW ==Eq ==Un
[10/22/2013 - 03:12:21PM] OnUpdate(): AW:+ RW:+ AC:- RC:- Eq:+ Un:+
[10/22/2013 - 03:12:26PM] OnItemRemoved(Container): FF000898 (base=A000D62 cell=32Ae7 3d=0 del=1) '[ObjectReference < (FF000898)>]' ==AW ==RW ->RC ==Eq ==Un
[10/22/2013 - 03:12:45PM] OnItemAdded(Container): FF000898 (base=A000D62 cell=32Ae7 3d=0 del=1) '[ObjectReference < (FF000898)>]' ==AW ==RW ->AC ==RC ==Eq ==Un
[10/22/2013 - 03:12:52PM] OnObjectEquipped(): FF000898 (base=A000D62 cell=32Ae7 3d=0 del=1) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:13:02PM] OnUpdate(): AW:+ RW:+ AC:+ RC:+ Eq:+ Un:+
[10/22/2013 - 03:13:07PM] OnObjectUnequipped(): FF000898 (base=A000D62 cell=32Ae7 3d=1 del=0) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un

We can see each cache slot get filled in one by one as each event is first triggered with an ObjectReference pointer. Since this item is not scripted, all of those received ObjectReference pointers continue to identify themselves as '[ObjectReference <...>]' and compare equal to each other, and none of the cached pointers ever break, even after the item is picked up and dropped several times, both manually by the player and via DropObject():

[10/22/2013 - 03:13:08PM] OnItemRemoved(world): FF000898 (base=A000D62 cell=32Ae7 3d=1 del=0) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:13:17PM] OnUpdate(): AW:+ RW:+ AC:+ RC:+ Eq:+ Un:+
[10/22/2013 - 03:13:25PM] OnItemAdded(world): FF000898 (base=A000D62 cell=32Ae7 3d=0 del=1) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:13:27PM] OnUpdate(): AW:+ RW:+ AC:+ RC:+ Eq:+ Un:+
[10/22/2013 - 03:13:33PM] OnItemRemoved(world): FF000898 (base=A000D62 cell=32Ae7 3d=1 del=0) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:13:55PM] calling player.AddItem([AW ref])
[10/22/2013 - 03:13:55PM] OnItemAdded(world): FF000898 (base=A000D62 cell=32Ae7 3d=0 del=1) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:14:04PM] OnUpdate(): AW:+ RW:+ AC:+ RC:+ Eq:+ Un:+
[10/22/2013 - 03:14:09PM] OnObjectEquipped(): FF000898 (base=A000D62 cell=32Ae7 3d=0 del=1) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:14:15PM] OnObjectUnequipped(): FF000898 (base=A000D62 cell=32Ae7 3d=0 del=1) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:14:22PM] OnItemRemoved(world): FF000898 (base=A000D62 cell=32Ae7 3d=1 del=0) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:14:26PM] OnUpdate(): AW:+ RW:+ AC:+ RC:+ Eq:+ Un:+
[10/22/2013 - 03:14:26PM] OnItemAdded(world): FF000898 (base=A000D62 cell=32Ae7 3d=0 del=1) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:14:49PM] calling player.DropObject([form])
[10/22/2013 - 03:14:49PM] OnItemRemoved(world): FF000898 (base=A000D62 cell=32Ae7 3d=1 del=0) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:14:49PM] DropObject(): FF000898 (base=A000D62 cell=32Ae7 3d=1 del=0) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:14:52PM] OnUpdate(): AW:+ RW:+ AC:+ RC:+ Eq:+ Un:+
[10/22/2013 - 03:14:55PM] OnItemAdded(world): FF000898 (base=A000D62 cell=32Ae7 3d=0 del=1) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:15:02PM] OnUpdate(): AW:+ RW:+ AC:+ RC:+ Eq:+ Un:+
[10/22/2013 - 03:15:09PM] OnObjectEquipped(): FF000898 (base=A000D62 cell=32Ae7 3d=0 del=1) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:15:27PM] OnUpdate(): AW:+ RW:+ AC:+ RC:+ Eq:+ Un:+
[10/22/2013 - 03:15:39PM] calling player.DropObject([form])
[10/22/2013 - 03:15:39PM] OnObjectUnequipped(): FF000898 (base=A000D62 cell=32Ae7 3d=1 del=0) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:15:39PM] OnObjectUnequipped(): FF000898 (base=A000D62 cell=32Ae7 3d=1 del=0) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:15:39PM] OnItemRemoved(world): FF000898 (base=A000D62 cell=32Ae7 3d=1 del=0) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:15:39PM] DropObject(): FF000898 (base=A000D62 cell=32Ae7 3d=1 del=0) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:15:47PM] OnUpdate(): AW:+ RW:+ AC:+ RC:+ Eq:+ Un:+
[10/22/2013 - 03:15:57PM] OnUpdate(): AW:+ RW:+ AC:+ RC:+ Eq:+ Un:+
[10/22/2013 - 03:16:07PM] OnUpdate(): AW:+ RW:+ AC:+ RC:+ Eq:+ Un:+
[10/22/2013 - 03:16:08PM] OnItemAdded(world): FF000898 (base=A000D62 cell=32Ae7 3d=0 del=1) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:16:20PM] calling player.DropObject([form])
[10/22/2013 - 03:16:20PM] DropObject(): FF000898 (base=A000D62 cell=32Ae7 3d=1 del=0) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:16:20PM] OnItemRemoved(world): FF000898 (base=A000D62 cell=32Ae7 3d=1 del=0) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:16:23PM] OnUpdate(): AW:+ RW:+ AC:+ RC:+ Eq:+ Un:+
[10/22/2013 - 03:16:43PM] calling [ObjectReference < (FF000898)>].Reset()
note: it vanished off the ground at this point
[10/22/2013 - 03:16:45PM] OnUpdate(): AW:+ RW:+ AC:+ RC:+ Eq:+ Un:+
[10/22/2013 - 03:16:56PM] calling player.AddItem([AW ref])
[10/22/2013 - 03:16:56PM] OnItemAdded(world): FF000898 (base=A000D62 cell=32Ae7 3d=0 del=1) '[ObjectReference < (FF000898)>]' ==AW ==RW ==AC ==RC ==Eq ==Un
[10/22/2013 - 03:17:09PM] OnUpdate(): AW:+ RW:+ AC:+ RC:+ Eq:+ Un:+

There are a few interesting things to note here, including several hints about how the game engine handles object references natively. I suspect that whenever an item is inside a container (or actor inventory), it actually has no ObjectReference, or perhaps it is just given a different reference (and perhaps this is why we sometimes see (ref As String) return things like "<Item 1 in container (00000014)>"). Here are some clues that support this interpretation:

None of the item events normally receive an ObjectReference pointer argument if the item is still in a container or inventory, unless the reference is persistent. If a reference exists at this time, and the event handlers are already equipped to receive it, why does the engine not provide it to the handlers unless it's persistent or the item is dropped to the world?

Every ObjectReference observed by Papyrus reports IsDeleted()==TRUE whenever the corresponding item is not on the ground, even if the pointer was just received by an event. What sense does it make for the engine to pass deleted references into Papyrus event handlers, if a non-deleted reference exists for the same item?

The CK wiki documentation for OnItemRemoved() refers to "the generated reference". If a non-persistent item in inventory has an ObjectReference of any kind, why is one "generated" when it is dropped to the world?

When the player drops items to the world that do not already have persistent references, the FormID numbering of the observed object references are not consistent. Try it: drop two non-persistent items and then click them each in the console to see their reference FormIDs. Now pick both up and drop them again in the opposite order: the engine recycles these reference FormIDs and re-uses them in the order that items are dropped, so the actual items end up with each other's previous reference FormIDs, rather than maintaining one consistent reference FormID for each distinct item.

These are all just curiosities for the moment, but as we get into the problematic edge cases, some of these quirks may help explain what's going on.