Add a backtrace command to debugger, add console.trace command, set Error.stack in constructor (fix #2490)

            Error.stack/stack dump now uses more standard file:line:col format
            Out of memory errors now show a backtrace (previously it was very hard to track these down)

Author: gfwilliams

.gdbinit

@@ -2,10 +2,10 @@ break jsAssertFail
 break jsError
 define jsvTrace
   print jsvTrace($arg0, 0)
-end   
+end
 define whereami
- print jslPrintPosition(jsiConsolePrintString, 0, lex->tokenLastStart)
- print jslPrintTokenLineMarker(jsiConsolePrintString, 0, lex->tokenLastStart, 0)
+ print jslPrintPosition(jsiConsolePrintString, 0, lex, lex->tokenLastStart)
+ print jslPrintTokenLineMarker(jsiConsolePrintString, 0, lex, lex->tokenLastStart, 0)
 end
 define typeof
   if (($arg0)->flags&JSV_VARTYPEMASK)>=JSV_NAME_STRING_0 && (($arg0)->flags&JSV_VARTYPEMASK)<=JSV_NAME_STRING_MAX
@@ -25,7 +25,7 @@ end
 define asm
   set  disassemble-next-line on
   show disassemble-next-line
-  echo now use stepi 
+  echo now use stepi
 end
 # Watchdog timer off for NRF52 devices
 define wdt_off
@@ -56,9 +56,6 @@ define execflags
   if execInfo.execute&EXEC_ERROR
     printf "EXEC_ERROR\n"
   end
-  if execInfo.execute&EXEC_ERROR_LINE_REPORTED
-    printf "EXEC_ERROR_LINE_REPORTED\n"
-  end
   if execInfo.execute&EXEC_FOR_INIT
     printf "EXEC_FOR_INIT\n"
   end
@@ -82,7 +79,7 @@ end
 
 define hook-run
     set $primask=0
-end 
+end
 
 define hook-continue
     set $primask=0

ChangeLog

@@ -5,6 +5,9 @@
             Bangle.js: g.findFont now attempts to use Intl:2 if there's room. Also fix memory leak
             nRF52840: Add E.getVDDH() method to get VDDH voltage
             Fix issue handling multi-line tempated strings pasted to REPL (2v26 regression)
+            Add a backtrace command to debugger, add console.trace command, set Error.stack in constructor (fix #2490)
+            Error.stack/stack dump now uses more standard file:line:col format
+            Out of memory errors now show a backtrace (previously it was very hard to track these down)
 
      2v26 : nRF5x: ensure TIMER1_IRQHandler doesn't always wake idle loop up (fix #1900)
             Puck.js: On v2.1 ensure Puck.mag behaves like other variants - just returning the last reading (avoids glitches when used with Puck.magOn)

src/jsflash.c

@@ -1414,8 +1414,10 @@ bool jsfLoadBootCodeFromFlash(bool isReset) {
 #endif
   if (jsiStatus & JSIS_FIRST_BOOT) {
     JsVar *code = jsfReadFile(jsfNameFromString(".bootPowerOn"),0,0);
-    if (code)
-      jsvUnLock2(jspEvaluateVar(code,0,0), code);
+    if (code) {
+      jsvUnLock2(jspEvaluateVar(code,0,".bootPowerOn",0), code);
+      jsiCheckErrors();
+    }
   }
 #endif
   // Load code in .boot0/1/2/3 UNLESS BTN1 IS HELD DOWN FOR BANGLE.JS ON FIRST BOOT (BTN3 for Dickens)
@@ -1434,14 +1436,17 @@ bool jsfLoadBootCodeFromFlash(bool isReset) {
     for (int i=0;i<4;i++) {
       filename[5] = (char)('0'+i);
       JsVar *code = jsfReadFile(jsfNameFromString(filename),0,0);
-      if (code)
-        jsvUnLock2(jspEvaluateVar(code,0,0), code);
+      if (code) {
+        jsvUnLock2(jspEvaluateVar(code,0,filename,0), code);
+        jsiCheckErrors();
+      }
     }
   }
   // Load normal boot code
   JsVar *code = jsfGetBootCodeFromFlash(isReset);
   if (!code) return false;
-  jsvUnLock2(jspEvaluateVar(code,0,0), code);
+  jsvUnLock2(jspEvaluateVar(code,0,"boot code",0), code);
+  jsiCheckErrors();
   return true;
 }
 

src/jsinteractive.c

@@ -137,7 +137,6 @@ JsErrorFlags lastJsErrorFlags = 0; ///< Compare with jsErrorFlags in order to re
 #ifdef USE_DEBUGGER
 void jsiDebuggerLine(JsVar *line);
 #endif
-void jsiCheckErrors();
 
 static void jsiPacketFileEnd();
 static void jsiPacketExit();
@@ -535,11 +534,13 @@ void jsiSoftInit(bool hasBeenReset) {
 
   // Run 'boot code' - textual JS in flash
   jsfLoadBootCodeFromFlash(hasBeenReset);
+  //  jsiCheckErrors is performed internally
 
   // Now run initialisation code
   JsVar *initCode = jsvObjectGetChildIfExists(execInfo.hiddenRoot, JSI_INIT_CODE_NAME);
   if (initCode) {
-    jsvUnLock2(jspEvaluateVar(initCode, 0, 0), initCode);
+    jsvUnLock2(jspEvaluateVar(initCode, 0, "initcode", 0), initCode);
+    jsiCheckErrors();
     jsvObjectRemoveChild(execInfo.hiddenRoot, JSI_INIT_CODE_NAME);
   }
 
@@ -565,11 +566,13 @@ void jsiSoftInit(bool hasBeenReset) {
 
   // Execute `init` events on `E`
   jsiExecuteEventCallbackOn("E", INIT_CALLBACK_NAME, 0, 0);
+  jsiCheckErrors();
   // Execute the `onInit` function
   JsVar *onInit = jsvObjectGetChildIfExists(execInfo.root, JSI_ONINIT_NAME);
   if (onInit) {
     if (jsiEcho()) jsiConsolePrint("Running onInit()...\n");
     jsiExecuteEventCallback(0, onInit, 0, 0);
+    jsiCheckErrors();
     jsvUnLock(onInit);
   }
 }
@@ -1528,7 +1531,7 @@ void jsiHandleNewLine(bool execute) {
 #endif
       {
         // execute!
-        JsVar *v = jspEvaluateVar(lineToExecute, 0, jsiLineNumberOffset);
+        JsVar *v = jspEvaluateVar(lineToExecute, 0, "REPL", jsiLineNumberOffset);
         // add input line to history
         bool isEmpty = jsvIsEmptyString(lineToExecute);
         // Don't store history if we're not echoing back to the console (it probably wasn't typed by the user)
@@ -2040,7 +2043,7 @@ static NO_INLINE bool jsiExecuteEventCallbackInner(JsVar *thisVar, JsVar *callba
   } else if (jsvIsFunction(callbackNoNames)) {
     jsvUnLock(jspExecuteFunction(callbackNoNames, thisVar, (int)argCount, argPtr));
   } else if (jsvIsString(callbackNoNames)) {
-    jsvUnLock(jspEvaluateVar(callbackNoNames, 0, 0));
+    jsvUnLock(jspEvaluateVar(callbackNoNames, 0, "event", 0));
   } else
     jsError("Unknown type of callback in Event Queue");
   return ok;
@@ -2146,7 +2149,7 @@ void jsiCtrlC() {
 /** Take an event for a UART and handle the characters we're getting, potentially
  * grabbing more characters as well if it's easy. If more character events are
  * grabbed, the number of extra events (not characters) is returned */
-int jsiHandleIOEventForSerial(JsVar *usartClass, IOEventFlags eventFlags, uint8_t *data, int length) {
+int jsiHandleIOEventForSerial(JsVar *usartClass, IOEventFlags eventFlags, uint8_t *data, unsigned int length) {
   int eventsHandled = length+2;
   JsVar *stringData = length ? jsvNewStringOfLength(length, (char*)data) : NULL;
   if (stringData) {
@@ -2178,7 +2181,7 @@ void jsiIdle() {
   bool wasBusy = false;
   IOEventFlags eventFlags;
   uint8_t eventData[IOEVENT_MAX_LEN];
-  int eventLen;
+  unsigned int eventLen;
   // ensure we can't get totally swamped by having more events than we can process.
   // Just process what was in the event queue at the start
   int maxEvents = jshGetEventsUsed();
@@ -2564,8 +2567,8 @@ void jsiIdle() {
         jsiSemiInit(false, &filename); // don't autoload code
         // load the code we specified
         JsVar *code = jsfReadFile(filename,0,0);
-        if (code)
-          jsvUnLock2(jspEvaluateVar(code,0,0), code);
+        if (code) // only supply the filename if we're sure it's zero terminated
+          jsvUnLock2(jspEvaluateVar(code,0,filename.c[sizeof(filename.c)-1] ? filename.c : "load",0), code);
       } else {
         jsiSoftKill();
         jspSoftKill();
@@ -2805,14 +2808,14 @@ void jsiDebuggerLoop() {
       itostr((JsVarInt)jslGetLineNumber() + (JsVarInt)lex->lineNumberOffset - 1, lineStr, 10);
     } else
 #endif
-    {
+    { // FIXME: Maybe if executing from a Storage file we use line numbers within that file?
       lineStr[0]=0;
     }
     size_t lineLen = strlen(lineStr);
     while (lineLen < sizeof(lineStr)-1) lineStr[lineLen++]=' ';
     lineStr[lineLen] = 0;
     // print the line of code, prefixed by the line number, and with a pointer to the exact character in question
-    jslPrintTokenLineMarker(vcbprintf_callback_jsiConsolePrintString, 0, lex->tokenLastStart, lineStr);
+    jslPrintTokenLineMarker(vcbprintf_callback_jsiConsolePrintString, 0, lex, lex->tokenLastStart, lineStr);
   }
 
   while (!(jsiStatus & JSIS_EXIT_DEBUGGER) &&
@@ -2822,7 +2825,7 @@ void jsiDebuggerLoop() {
     jshIdle();
     // If we have too many events (> half full) drain the queue
     uint8_t eventData[IOEVENT_MAX_LEN];
-    int eventLen;
+    unsigned int eventLen;
     while (jshGetEventsUsed()>IOBUFFERMASK*1/2 &&
            !(jsiStatus & JSIS_EXIT_DEBUGGER) &&
            !(execInfo.execute & EXEC_CTRL_C_MASK)) {
@@ -2906,7 +2909,8 @@ void jsiDebuggerLine(JsVar *line) {
                       "finish / f         - finish execution of the function call\n"
                       "print ... / p ...  - evaluate and print the next argument\n"
                       "info locals / i l)    - output local variables\n"
-                      "info scopechain / i s - output all variables in all scopes\n");
+                      "info scopechain / i s - output all variables in all scopes\n"
+                      "bt                 - print backtrace\n");
     } else if (!strcmp(id,"quit") || !strcmp(id,"q")) {
       jsiStatus |= JSIS_EXIT_DEBUGGER;
       execInfo.execute |= EXEC_INTERRUPTED;
@@ -2962,6 +2966,8 @@ void jsiDebuggerLine(JsVar *line) {
        } else {
          jsiConsolePrint("Unknown command\n");
        }
+    } else if (!strcmp(id,"bt")) {
+      jslPrintStackTrace(vcbprintf_callback_jsiConsolePrintString, NULL, oldLex);
     } else
       handled = false;
   }

src/jsinteractive.h

@@ -63,6 +63,9 @@ bool jsiExecuteEventCallbackName(JsVar *obj, const char *cbName, unsigned int ar
 /// Utility version of jsiExecuteEventCallback for calling events on global variables
 bool jsiExecuteEventCallbackOn(const char *objectName, const char *cbName, unsigned int argCount, JsVar **argPtr);
 
+/// Check for and report/handle interpreter errors (can be called after executing JS code)
+void jsiCheckErrors();
+
 /// Create a timeout in JS to execute the given native function (outside of an IRQ). Returns the index
 JsVar *jsiSetTimeout(void (*functionPtr)(void), JsVarFloat milliseconds);
 /// Clear a timeout in JS given the index returned by jsiSetTimeout

src/jslex.c

@@ -948,6 +948,8 @@ void jslInit(JsVar *var) {
 #ifndef ESPR_NO_LINE_NUMBERS
   lex->lineNumberOffset = 0;
 #endif
+  lex->functionName = NULL;
+  lex->lastLex = NULL;
   // set up iterator
   jsvStringIteratorNew(&lex->it, lex->sourceVar, 0);
   jsvUnLock(lex->it.var); // see jslGetNextCh
@@ -1502,7 +1504,7 @@ void jslPrintTokenisedString(JsVar *code, vcbprintf_callback user_callback, void
   jsvStringIteratorFree(&it);
 }
 
-void jslPrintPosition(vcbprintf_callback user_callback, void *user_data, size_t tokenPos) {
+void jslPrintPosition(vcbprintf_callback user_callback, void *user_data, JsLex *lex, size_t tokenPos) {
   size_t line,col;
 #if !defined(SAVE_ON_FLASH) && !defined(ESPR_EMBED)
   if (jsvIsNativeString(lex->sourceVar) || jsvIsFlashString(lex->sourceVar)) {
@@ -1513,7 +1515,7 @@ void jslPrintPosition(vcbprintf_callback user_callback, void *user_data, size_t
       JsVar *fileStr = jsvAddressToVar(fileAddr, jsfGetFileSize(&header));
       jsvGetLineAndCol(fileStr, tokenPos + stringAddr - fileAddr, &line, &col);
       JsVar *name = jsfVarFromName(header.name);
-      cbprintf(user_callback, user_data,"line %d col %d in %v\n", line, col, name);
+      cbprintf(user_callback, user_data,"%v:%d:%d", name, line, col);
       jsvUnLock2(fileStr,name);
       return;
     }
@@ -1524,10 +1526,10 @@ void jslPrintPosition(vcbprintf_callback user_callback, void *user_data, size_t
   if (lex->lineNumberOffset)
     line += (size_t)lex->lineNumberOffset - 1;
 #endif
-  cbprintf(user_callback, user_data, "line %d col %d\n", line, col);
+  cbprintf(user_callback, user_data, ":%d:%d", line, col);
 }
 
-void jslPrintTokenLineMarker(vcbprintf_callback user_callback, void *user_data, size_t tokenPos, char *prefix) {
+void jslPrintTokenLineMarker(vcbprintf_callback user_callback, void *user_data, JsLex *lex, size_t tokenPos, char *prefix) {
   size_t line = 1,col = 1;
   jsvGetLineAndCol(lex->sourceVar, tokenPos, &line, &col);
   size_t startOfLine = jsvGetIndexFromLineAndCol(lex->sourceVar, line, 1);
@@ -1568,3 +1570,21 @@ void jslPrintTokenLineMarker(vcbprintf_callback user_callback, void *user_data,
   user_callback("^\n", user_data);
 }
 
+void jslPrintStackTrace(vcbprintf_callback user_callback, void *user_data,  JsLex *lex) {
+  while (lex) {
+    user_callback("    at ", user_data);
+    if (lex->functionName) {
+      // can't use cbprintf here as it may try and allocate a var
+      // and we want to be able to use this when we're out of memory
+      char functionName[JSLEX_MAX_TOKEN_LENGTH];
+      jsvGetString(lex->functionName, functionName, sizeof(functionName));
+      user_callback(functionName, user_data);
+      user_callback(" (", user_data);
+    }
+    jslPrintPosition(user_callback, user_data, lex, lex->tokenLastStart);
+    user_callback(lex->functionName ? ")\n":"\n", user_data);
+    jslPrintTokenLineMarker(user_callback, user_data, lex, lex->tokenLastStart, 0);
+
+    lex = lex->lastLex; // go down to next lexer in list
+  }
+}

src/jslex.h

@@ -174,6 +174,11 @@ typedef struct JsLex
    */
   JsVar *sourceVar; // the actual string var
   JsvStringIterator it; // Iterator for the string
+
+  /// For stack traces - this is just a pointer to a function name if we have one (it's not 'owned')
+  JsVar *functionName;
+  /// For stack traces - this is just a pointer to the previous Lex on the stack
+  struct JsLex *lastLex;
 } JsLex;
 
 // The lexer
@@ -224,10 +229,13 @@ bool jslNeedSpaceBetween(unsigned char lastch, unsigned char ch);
 void jslPrintTokenisedString(JsVar *code, vcbprintf_callback user_callback, void *user_data);
 
 /// Print position in the form 'line X col Y'
-void jslPrintPosition(vcbprintf_callback user_callback, void *user_data, size_t tokenPos);
+void jslPrintPosition(vcbprintf_callback user_callback, void *user_data, JsLex *lex, size_t tokenPos);
 
 /** Print the line of source code at `tokenPos`, prefixed with the string 'prefix' (0=no string).
  * Then, underneath it, print a '^' marker at the column tokenPos was at  */
-void jslPrintTokenLineMarker(vcbprintf_callback user_callback, void *user_data, size_t tokenPos, char *prefix);
+void jslPrintTokenLineMarker(vcbprintf_callback user_callback, void *user_data, JsLex *lex, size_t tokenPos, char *prefix);
+
+/** Prints a full stack trace to the current callback function */
+void jslPrintStackTrace(vcbprintf_callback user_callback, void *user_data,  JsLex *lex);
 
 #endif /* JSLEX_H_ */