Inhibit on("destroy:attribute") during character deletion

Hello all, We have been trying since several weeks to narrow down the cause of an API crash in our system. First it is important to understand that we have an API and a custom character sheet meant to be working together, the API expanding some of the character sheet functionalities. Since several weeks, we had from time to time a crash as below: TypeError: Cannot read property 'attribs' of undefined TypeError: Cannot read property 'attribs' of undefined at attrList (/home/node/d20-api-server/sheetworker_listeners.js:203:15) at Worker.onmessage (/home/node/d20-api-server/sheetworker_listeners.js:277:17) at ChildProcess.<anonymous> (/home/node/d20-api-server/node_modules/tiny-worker/lib/index.js:90:21) at ChildProcess.emit (events.js:310:20) at emit (internal/child_process.js:876:12) at processTicksAndRejections (internal/process/task_queues.js:85:21) Today, I could finally pinpoint a trigger for the fault when deleting certain characters, and could narrow that those characters are those with "links". Links is a functionality that we introduced in our API/charactersheet system, that allows the user to make values of a repitem depend from another repitem. This is done by the API creating bidirectional references to the other repitem rowid (stored in attributes LinksGetValue and LinksProvideValue). In order to "clean" up any dead link created by the deletion of one end of the link we have in the API the following routine: on("destroy:attribute", function (attr ) { 'use strict'; try { let nm = attr.get( "name" ); // If it is a link attribute, it is probably because the row has been deleted. // If it is a link, go through the links, to / from the linked item and remove the other half of the links. if( nm.endsWith( "_LinksGetValue" ) || nm.endsWith( "_LinksProvideValue" )) { // One half of a link has been deleted. remove the link from the other half. //log("destroying"); log( attr); let arr = attr.get( "max" ).split( "," ); if( arr.length > 0 ) { let ED = new Earthdawn.EDclass(); let edParse = new ED.ParseObj( ED ); edParse.charID = attr.get( "_characterid" ); for( let i = 0; i < arr.length; ++i ) if( nm.endsWith( "_LinksGetValue" )) { // LinksGetValue are of form comma delimited list of fully qualified attributes, maybe more than one seperated by plus signs. let a2 = arr[ i ].split( "+" ), cnt = 0; for( let j = 0; j < a2.length; ++j ) { if( a2[ j ].startsWith( "repeating_") && cnt < 1 ) { // if it is not linking to a repeating section, then it is not bidirectional, and we don't have anything to do for this link. edParse.ChatMenu( [ "ChatMenu", "LinkRemoveHalf", Earthdawn.buildPre( Earthdawn.repeatSection( 3, a2[ j ] ), Earthdawn.repeatSection( 2, a2[ j ] )) + "LinksProvideValue", Earthdawn.repeatSection( 2, nm )] ); ++cnt; } } } else // LinksProviceValue are comma delimited lists of form (code);(rowID). edParse.ChatMenu( [ "ChatMenu", "LinkRemoveHalf", Earthdawn.buildPre( Earthdawn.getParam( arr[ i ], 1, ";" ), Earthdawn.getParam( arr[ i ], 2, ";" )) + "LinksGetValue", Earthdawn.repeatSection( 2, nm )] ); } } // This should remove this rowID (last parameter) from the referenced lists. else if( nm.endsWith( "_SPM_spRowID" )) { // Spell matrix has been deleted. let ED = new Earthdawn.EDclass(); let edParse = new ED.ParseObj( ED ); edParse.charID = attr.get( "_characterid" ); edParse.TuneMatrix( [ "Tune", "inMatrix" ]); } else if( nm.endsWith( "_RowID" )) { // A row has been deleted. If the row has a Token action, delete it. let rowID = Earthdawn.repeatSection( 2, nm ); let ab = findObjs({ _type: "ability", _characterid: attr.get( "_characterid" )}); _.each( ab, function (abObj) { if( abObj.get( "action" ).indexOf( rowID ) !== -1) abObj.remove(); }); } } catch(err) { log( "on destroy attribute() error caught: " + err ); } }); // end on("destroy:attribute") I could narrow down that it seems that this routine that is meant to cleanup a dead link when a single repitem is deleted, actually was causing the fault when the whole character was deleted. I am now searching for solutions, and in particular if there would be a way to inhibit the "destroy:attribute" detection, when it is caused by a character deletion. Thanks in advance for your support

I would simply add in a gate to check for whether the character exists or not. If it doesn't you just return. Something like this at the top of the function: let character = getObj('character',attr.get('characterid')); if(!character) return;

Thanks a lot Scott for once a again the valuable support! i ll try it!

OK, so it doesn't seem to be it... Even gated by the existence of the character, when destroying a character, I have the whole list of attributes being destroyed... So my guess is that the roll20 routine first destroys all the attributes one by one, and once finished, destroys the character itself... I went on, ad found more interesting stuff... It all seems to happen in the routine that is called linkremovehalf, that is called for every attribute that has links:           case "linkremove":        // ChatMenu: linkRemove: (code: T, NAC, SK, SPM, WPN): (rowID): ( Attribute, T, SK, WPN, DSP, NAC, or WPN): linked rowID to be removed or Attrubite name.           case "linkremovehalf": {    // ChatMenu: linkRemoveHalf: attribute name, rowID to remove.                 // linkRemove if the main entry point, called when the user presses a button requesting a link be removed.                 // linkRemoveHalf is a secondary entry point, called by the on destroy routine when it detects that a linked  row has been deleted, it removes the other half of the link.             let done = 0;                   // Given a fully qualified argument name (repeating_talents_XXX_T_LinksProvideValue), and a rowID,                   // will remove any links matching that rowID from the named argument.             function linkRemove( linkName, rowID, countIt ) {               let obj = Earthdawn.findOrMakeObj({ _type: "attribute", _characterid: edParse.charID, name: linkName }, "");               log ("linkRemove" + linkName + "  rid " + rowID + " countit  " + countIt);                // let objtmp = findObjs({ _type: "attribute", _characterid: edParse.charID, name: linkName });                // log( "removing links " + linkName + "  obj " + JSON.stringify(objtmp));                // if (objtmp=== undefined || objtmp===[]) { log("removing links: other half of the link doesn't exist");return;}                // let obj=objtmp[0];                log ("obj is " + JSON.stringify(obj));                if (obj=== undefined) { log("removing links: other half of the link doesn't exist");return;}               let dlst = obj.get( "current" ),                 llst = obj.get( "max" );                 log (" got dlst and llst " + JSON.stringify(dlst) + "   " + JSON.stringify(llst));               if( !llst || llst.length < 5 ) {      // there are no existing links.                 llst = [];                 dlst = [];               } else {        // There are existing links.                 llst = llst.split( "," );                 dlst = dlst.split( "," );                 if( llst.length != dlst.length ) {                   edParse.chat( "Warning! internal data mismatch in linkRemove.", Earthdawn.whoFrom.apiError);                   edParse.edClass.errorLog( "Warning! internal data mismatch in linkRemove.", Earthdawn.whoFrom.apiError);                   edParse.edClass.errorLog( dlst);                   log( llst);                   llst = [];                   dlst = [];                 }               }               for( let i = llst.length - 1; i > -1; --i )                 if(llst[ i ].indexOf( rowID ) !== -1 ) {                   llst.splice( i, 1);                   dlst.splice( i, 1);                   if( countIt )                     ++done;                 }               Earthdawn.set( obj, "max", llst.join(), "" );               log( "setww " + obj.get( "name" ) + "   from: " + obj.get( "current" ) + "   to: " + dlst.join());               Earthdawn.setWithWorker( obj, "current", dlst.join(), "" );               // Earthdawn.set( obj, "current", dlst.join(), "" );               log( "setww successful "); //              edParse.addSWflag( "Trigger2", obj.get( "name" )); //              edParse.addSWflag( "Trigger", obj.get( "name" ) + ": " + llst.join());             } // end linkRemove             if (ssa[ 1 ].toLowerCase() === "linkremovehalf") {               if( ssa.length < 3 )    // Make sure got a valid command line.                 return;               linkRemove( ssa[ 2 ], ssa[ 3 ] );             } Note in bold the use of a "custom" setWithWorker function with some additional gatekeeping. Earthdawn.setWithWorker = function( obj, att, val, dflt ) { 'use strict'; try { // log( "setww " + obj.get("name") + " val " + val); if(( val === undefined && dflt != undefined ) || (val !== val)) { // val !== val is the only way to test for it equaling NaN. Can't use isNan() because many values are not supposed to be numbers. But we do want to test for val having been set to NaN. log( "Warning!!! Earthdawn:setWithWorker() Attempting to set '" + att + "' to " + val + " setting to '" + dflt + "' instead. Object is ..."); log( obj ); obj.setWithWorker( att, (dflt === undefined) ? "" : dflt ); } else obj.setWithWorker( att, (val === undefined) ? "" : val ); } catch(err) { log( "Earthdawn:setWithWorker() error caught: " + err ); } } // end of setWithWorker() With that, I could go on a test case, with a character that has one repitem repeating_discipline, linked to two repitems repeating_matrix. Here is the log I get 1-   "destroying repeating_matrix_-MqeJ44Z7Ml4KB53Euxk_SPM_LinksGetValue" 2-  "linkRemoverepeating_discipline_-MqeJ0noytpLaVCxGVAZ_DSP_LinksProvideValue  rid -MqeJ44Z7Ml4KB53Euxk countit  undefined" "obj is {\"name\":\"repeating_discipline_-MqeJ0noytpLaVCxGVAZ_DSP_LinksProvideValue\",\"current\":\",\",\"max\":\"SPM;-MqeJ44Z7Ml4KB53Euxk,SPM;-MqeJ44Z7Ml4KB53Euxl\",\"_id\":\"-MqeJ6apgdcZZptCopT6\",\"_type\":\"attribute\",\"_characterid\":\"-MqeJ0I7TwKuvIGRPBJ_\"}" 3- " got dlst and llst \",\"   \"SPM;-MqeJ44Z7Ml4KB53Euxk,SPM;-MqeJ44Z7Ml4KB53Euxl\"" "setww repeating_discipline_-MqeJ0noytpLaVCxGVAZ_DSP_LinksProvideValue   from: ,   to: " "setww successful " 4- "destroying repeating_discipline_-MqeJ0noytpLaVCxGVAZ_DSP_LinksProvideValue" 5-"linkRemoverepeating_matrix_-MqeJ44Z7Ml4KB53Euxl_SPM_LinksGetValue  rid -MqeJ0noytpLaVCxGVAZ countit  undefined" "obj is {\"name\":\"repeating_matrix_-MqeJ44Z7Ml4KB53Euxl_SPM_LinksGetValue\",\"current\":\"Illusionist\",\"max\":\"repeating_discipline_-MqeJ0noytpLaVCxGVAZ_DSP_Circle\",\"_id\":\"-MqeJ83sb-Z5gq2X_zLL\",\"_type\":\"attribute\",\"_characterid\":\"-MqeJ0I7TwKuvIGRPBJ_\"}" " got dlst and llst \"Illusionist\"   \"repeating_discipline_-MqeJ0noytpLaVCxGVAZ_DSP_Circle\"" "setww repeating_matrix_-MqeJ44Z7Ml4KB53Euxl_SPM_LinksGetValue   from: Illusionist   to: " "setww successful " TypeError: Cannot read property 'attribs' of undefined TypeError: Cannot read property 'attribs' of undefined     at attrList (/home/node/d20-api-server/sheetworker_listeners.js:203:15)     at Worker.onmessage (/home/node/d20-api-server/sheetworker_listeners.js:277:17)     at ChildProcess.<anonymous> (/home/node/d20-api-server/node_modules/tiny-worker/lib/index.js:90:21)     at ChildProcess.emit (events.js:310:20)     at emit (internal/child_process.js:876:12)     at processTicksAndRejections (internal/process/task_queues.js:85:21) OK, so what we can see: 1- It destroys one of the repeating_matrix… rowId ending with k  2- As the Matrix had a link to the repeating_discipline, it asks the repeating_discipline to clean the deadlink 3- Everything seems fins in removeLink, with the link to the 2 matrixes being detected 4- It then proceeds trying to destroy the repeating_discipline 5- You will note that it calls the linkremove only on the second matrix (rowId ending by l), so it looks it susccessfully destroed the first link 6- it has time to get to the end of removelink before crashing … Now, because the crash happens around the setwithworker function, I got suspicious, and decided to get back to a set instead of setwithworkers, and it didnt crash  "destroying repeating_matrix_-MqeKoEmm0Ys3OJZ6p73_SPM_LinksGetValue" "linkRemoverepeating_discipline_-MqeKdDh7tqcA4ZRNrBn_DSP_LinksProvideValue  rid -MqeKoEmm0Ys3OJZ6p73 countit  undefined" "obj is {\"name\":\"repeating_discipline_-MqeKdDh7tqcA4ZRNrBn_DSP_LinksProvideValue\",\"current\":\",\",\"max\":\"SPM;-MqeKoEmm0Ys3OJZ6p73,SPM;-MqeKoEmm0Ys3OJZ6p74\",\"_id\":\"-MqeKrPV5Mx35Gy9nazW\",\"_type\":\"attribute\",\"_characterid\":\"-MqeKcZVcZhdxtcik9Md\"}" " got dlst and llst \",\"   \"SPM;-MqeKoEmm0Ys3OJZ6p73,SPM;-MqeKoEmm0Ys3OJZ6p74\"" "setww repeating_discipline_-MqeKdDh7tqcA4ZRNrBn_DSP_LinksProvideValue   from: ,   to: " "setww successful " "destroying repeating_discipline_-MqeKdDh7tqcA4ZRNrBn_DSP_LinksProvideValue" "linkRemoverepeating_matrix_-MqeKoEmm0Ys3OJZ6p74_SPM_LinksGetValue  rid -MqeKdDh7tqcA4ZRNrBn countit  undefined" "obj is {\"name\":\"repeating_matrix_-MqeKoEmm0Ys3OJZ6p74_SPM_LinksGetValue\",\"current\":\"Illusionist\",\"max\":\"repeating_discipline_-MqeKdDh7tqcA4ZRNrBn_DSP_Circle\",\"_id\":\"-MqeKt2chBMcOklYRHy4\",\"_type\":\"attribute\",\"_characterid\":\"-MqeKcZVcZhdxtcik9Md\"}" " got dlst and llst \"Illusionist\"   \"repeating_discipline_-MqeKdDh7tqcA4ZRNrBn_DSP_Circle\"" "setww repeating_matrix_-MqeKoEmm0Ys3OJZ6p74_SPM_LinksGetValue   from: Illusionist   to: " "setww successful " "destroying repeating_matrix_-MqeKoEmm0Ys3OJZ6p74_SPM_LinksGetValue" You can see that the log has now one additional line with the destruction of the 2nd repeating_matrix (so it has been crashing somewhere around the time between writing something in this repitem with setwithworkers and the time where item got destroyed)... It is strange to me that the log after the setwithworker is logged (as if the setwithworker operation had completed), but that changing this line actually removes the crash (I still need in certain other cases the worker to detect the change, so I don't want to just go to just keep the set)... As setwithworker is asynchronous, and there is no callback, I suspect that it is trying actually to write, while it is actually already in the process of being destroyed... Any safeguard you could see in our custom setwithworker to avoid trying to write in a variable that is already being destroyed ? Any other suggestion ?

setWithWorkers() is a pretty short function which mostly just juggles parameters before invoking this.set() with them, so it's surprising there's that much difference in behaviour. But it looks like that might be just enough of a call stack nudge to leave a .set() trying to run after the character is deleted and their .attribs property no longer exists. It's also potentially possible that .set() fires an event that stops the parent object from being modified, but that the event isn't triggered properly when setWithWorker() is invoked.... which would be odd, since setWithWorker() hands the load straight to set(), but you never know. Where is the function which removes the character? A simple (but hackier) option would be to throw a setTimeout() at the character delete to give the attribute removal a bit of headroom. A non-hacky but more difficult solution would be to have the involved functions as async functions (including the calling function, of course) which allows you total control over timing with 'await' and with functions like Promise.all and Promise.race.... it's unlikely to be worth that much rewriting unless there are other problems cropping up, or if different users are getting slightly different errors - that'd probably be a sign that you have a few async timing issues and the move would be worthwhile.

Thanks... There is actually no function deleting the character... It is the character delete through the roll20 interface... I have found a workaround by noticing the first character that gets deleted on any character, and inhibiting all the rest if this attribute has been deleted... But it lets me slightly worried... The code is full of try/catch to avoid crashing the API, and knowing that I have a case where setwithworkers was actually able to crash it, and solving it by working around it rather than adressing the rootcause by defensive code lets me fearing it will come back through another sequence of events

Ohhh, sorry I just re-read the OP. So this all fires after you delete the character? Then yeah, stopping the code from executing is probably the best solution. Another way of doing that would be to use a setTimeout with Scott's suggestion above - that will give Roll20 time to scrub the character before checking if it exists. Since the error looks like it's coming from the API's event hub, you could also try a character check immediately before any setWithWorkers() call, that would at least narrow the window where an error could happen. But really, the setTimeout is probably the easiest option. Scrubbing a dead linked attribute isn't a particularly urgent action, so you can be pretty generous with the timing. The rest of the code just moves to another function (for readability, nothing more), and your handler looks like this: on('destroy:attribute', () => { setTimeout(() => { let characterExists = getObj('character',attr.get('characterid')); if (characterExists) mainFunction(); }, 500); });

Thanks a lot!