Very slow "Logs" with Google Apps Script V8 vs Rhino?

Question

With Rhino, Logs dialog ("command + Enter" or Logs from View menu) shows logs instantly. However, with test projects using V8 engine it takes 10-20 seconds to load even the simplest logs, with a message "Waiting for logs, please wait..."

Both, "Logger.log" or "console.log" are slow to load logs. Is anyone else experiencing the same type of slowness? Is this expected with the new engine?

Here's a basic function I used for testing:

function logTest() {
 Logger.log("log test");
}

Car

Answer 1

I noticed the same thing and there is an issue about it already.

I've been using the below script. It's probably not bullet proof but for me it's better than waiting for the log. I also notice that if you have an error and go to View Executions that the logs appear to come out there now even before we get them on the script editor.

Issue Link: https://issuetracker.google.com/issues/149519063

function MyLogger(s,t=5) {
  const cs=CacheService.getScriptCache();
  const cached=cs.get("Logger");
  const ts=Utilities.formatDate(new Date(), SpreadsheetApp.getActive().getSpreadsheetTimeZone(), "yy/MM/dd HH:mm:ss")
  if(cached) {
    var v=Utilities.formatString('%s<br />[%s] - %s',cached,ts,s);   
  }else{
    var v=Utilities.formatString('[%s] - %s',ts,s);
  }
  cs.put("Logger",v,t);
  SpreadsheetApp.getUi().showModelessDialog(HtmlService.createHtmlOutput(v), 'My Logger');
}

Another version of MyLogger():

function MyLogger(s,d=true,w=800,h=400,t=5) {
  const cs=CacheService.getScriptCache();
  const cached=cs.get("Logger");
  const ts=Utilities.formatDate(new Date(), SpreadsheetApp.getActive().getSpreadsheetTimeZone(), "MM|dd|HH:mm:ss")
  if(cached) {
    var v=Utilities.formatString('%s<br />[%s] - %s',cached,ts,s);   
  }else{
    var v=Utilities.formatString('[%s] - %s',ts,s);
  }
  cs.put("Logger",v,t);
  //allows logging without displaying.
  if(d) {
    const a='<br /><input type="button" value="Exit" onClick="google.script.host.close();" />';
    const b='<br /><input type="button" value="Exit" onClick="google.script.host.close();" /><br />';
    SpreadsheetApp.getUi().showModelessDialog(HtmlService.createHtmlOutput(b+v+a).setWidth(w).setHeight(h), 'My Logger');
  }
}

Workingman

To add to this, I've found it faster to have log lines emailed to me than waiting for the logs. I also don't think they will ever fix the issue. – Quartet

This is an important tool for google google to be neglecting it for this long... What's going on? Does it have to do with the rumors about a new app script IDE coming out? – Brokendown

@Workingman I'm not sure how to use your custom Logger. It could be a viable alternative for now. – Brokendown

Answer 2

another simple approach for a custom logger (for sheets) is define this function to write to a 'log' sheet

const log=(...items)=>{
  SpreadsheetApp.getActive().getSheetByName("log").appendRow(items)
}

and given a sheet called log, it will append arguments into cells of a new row, when called like

log(1,0,2,"a","b", "etc")

also has the benefit of creating a log when called via web app execution (which seemed to not invoke Logger in a retrievable way, as far as I could tell).

Weingarten

Answer 3

I have done some modification to @blueSkys Code

Edit 1 : Added provision to get arrays as well

 const log=(...data)=>{
 for (i=0; i< data.length;i++){
  if(typeof data[i] === 'object'){
  data[i] = data[i].join("//");
};
};
data.unshift(new Date());
  SpreadsheetApp.openById('1E9s2vI21eRlcnoqaVAF4wCUm4Ojn2Lpv62TM6Xw17Z4').getSheetByName('log').appendRow(data);
}

Also Created Video for a detailed guide

https://youtu.be/JQpbB5lR4eY

Instantaneous

Answer 4

Thanks for the insight, the code below runs well in GAS:

/**
 * @description Class: Logger helper, writes log information to tab sheet 'log' for the active spreadsheet 
 * @tutorial https://mcmap.net/q/24675/-why-does-console-log-say-undefined-and-then-the-correct-value-duplicate
 * @param N/A
 * @return {Object}
 */
class ConsoleX {
  constructor(){
    this.setSS('**** Log Initialized ****');
    this.timeStart = 0;
    this.timerBase = {};
  };
  
  log(...data){
    let dataY = '';
    data.forEach(c => {
      dataY += c;
    })
    this.setSS(`${[dataY]}`);
    Logger.log(`${[dataY]}`);
  };
  
  setSS(data){
    data = [data];
    data.unshift(new Date());
    SpreadsheetApp.getActive().getSheetByName(logFileName).appendRow(data);
  };
  
  getLogs(dataX){
    this.setSS(`${[dataX]}\n${Logger.getLog()}`);
  }

  time(data = 'base1'){
    let dateX = new Date();
    this.timerBase[data] = dateX.getTime();
  };
  
  timeEnd(data = 'base1'){
    let dateX = new Date();
   this.log(`${data}: ${(dateX.getTime() - this.timerBase[data])/1000}(ms)`);
  
  };
  
  clear() {
  SpreadsheetApp.getActive().getSheetByName(logFileName).clear({contentsOnly: true});
}
  
};// END ConsoleX


/**
 * @description Function: Test logging methods 
 * @tutorial https://mcmap.net/q/24675/-why-does-console-log-say-undefined-and-then-the-correct-value-duplicate
 * @param AS PER METHOD
 * @return {undefine}
 */
function testLog(){
  let testdata = {name:'hello', value:'world'};
  Logger.log('From Logger: ', testdata);
  test = new ConsoleX();
  test.time('**** Time')
  test.log('**** Standard Log: HELLO WORLD');
  test.log('**** Templating Log: THIS IS GOOD: ', 10*10, ` and ${100/2}`);
  test.getLogs('**** Logger Historical Data: Looking Good :)');
  test.getLogs();
  test.timeEnd('**** Time')
};

function testClear(){
  test = new ConsoleX();
  test.clear();

};

Burse

Answer 5

The following function has done the trick for me... quick and dirty:

    function logOut(message){
      var ui = SpreadsheetApp.getUi();
      var html  = HtmlService.createHtmlOutput('<h1>'+message+'</h1>');
      ui.showModalDialog(html,'Logs');
    }

It creates a pop up window showing what would otherwise be shown through Logger.log(message)

Melany