Soluzione al superamento del limite di tempo massimo di esecuzione consentito

Come è noto i servizi di Google Apps Script impongono quote giornaliere e limitazioni su alcune funzionalità, superando o una quota o una limitazione lo script genererà un'eccezione e la sua esecuzione si interromperà.

Una situazione di superamento di una quota, trattata nell'articolo 'Exceeded maximum execution time', è quella riferita al limite massimo del tempo di esecuzione dello script che, da Aprile 2014, è passato da 5 minuti a 6 minuti di esecuzione continua (con un limite massimo di esecuzione giornaliera, come indicato nella relativa documentazione, Quotas for Google Services). Coloro che aderiscono al programma Early Access invece, vedranno questo limite salire a 30 minuti ad esecuzione (aggiornamento: ad Agosto 2018 il limite di 30 minuti ad esecuzione è stato esteso anche agli account G Suite Business / Enterprise / EDU che non aderiscono al programma).

Considerando che per accedere all'Early Access è necessario avere un account G Suite Business (che è un servizio a pagamento rivolto principalmente alle agenzie) e che la conferma di adesione al programma è a discrezione del Team Google, ho pensato ad un modo alternativo per poter garantire il completamento delle operazioni di uno script, in modo automatico, in caso l'esecuzione dello stesso superi il limite massimo consentito.

Facendo un giro in rete ho trovato che l'approccio risolutivo che avevo ipotizzato era già stato discusso in un post su stackoverflow, tuttavia nei commenti si parla di approccio deprecato così come di alcuni metodi utilizzati nello script, pertanto ho voluto approfondire la questione ed ho realizzato due funzioni, una di prova che genera l'errore (per evidenziare l'effettivo limite) e l'altra che arriva al completamento dell'operazione, il tutto adeguatamente documentato e commentato.

Allo scopo di questo test ho creato uno script associato ad uno Spreadsheet (bound-script) che non fa altro che effettuare un loop per 30 volte dove, ad ogni ciclo, scrive il numero del contatore del ciclo a partire dalla prima cella della prima colonna, attende 15 secondi (per mezzo di uno sleep), effettua un flush dello Spreadsheet (per maggiori informazioni rimando all'articolo 'A cosa serve Spreadsheet.flush() e quando conviene usarlo') per poi scrivere nel log il lasso di tempo trascorso e riniziare il ciclo scrivendo nella seconda riga della prima colonna e proseguendo con le stesse operazioni appena descritte.

Il codice di cui sopra è il seguente:

// Funzione che se eseguita genera l'errore 'Limite massimo del tempo di esecuzione superato'

function testFunction() {
  var sheet = SpreadsheetApp.getActive().getActiveSheet().clear();
  var start = new Date().getTime();
  for (i=1; i<=30; i++) {
    sheet.getRange(i, 1).setValue(i);
    Utilities.sleep(15000);
    SpreadsheetApp.flush();
    var lap = new Date().getTime();
    Logger.log("Tempo trascorso per la scrittura continua di " + i + " celle: " + (lap - start));
  }
  var stop = new Date().getTime();
  Logger.log("Tempo di esecuzione totale dello script: " + (stop - start));  
}

Osservando lo Spreadsheet durante l'esecuzione è possibile (grazie al metodo flush) osservare che ogni 15 secondi un valore viene scritto in una cella, ma ad un certo punto il processo di scrittura sembra non proseguire oltre un certo valore (nel caso specifico 24) che è inferiore al numero di cicli previsto dalla funzione, ovvero 30 (Fig. 1):

Fig. 1 - Valori nello Spreadsheet non completati dallo script per il superamento del tempo massimo di esecuzione consentito

Osservando l'editor di script dal quale la funzione è stata avviata è facile comprenderne il motivo... il limite massimo del tempo di esecuzione è stato superato, Fig. 2:

Fig. 2 - Errore nell'editor di script dovuto al limite di tempo massimo di esecuzione consentito

Dando uno sguardo al log qualsiasi eventuale dubbio viene scongiurato, Fig. 3:

Fig. 3 - Log dello script che ha generato l'errore

Si osserva infatti che i millisecondi totali di esecuzione dello script prima che si fermasse alla riga 23 (calcolati per differenza tra il momento in cui viene inserita la riga nel log ed il tempo 0 di avvio dello script) sono circa 350000 (che corrispondono a 5,83 minuti), il tempo giusto per far scrivere la riga 24 ma non per poter attendere i successivi 15 secondi dello sleep (corrispondenti a 0,25 minuti) che sommati all'ultimo tempo rilevato superano i 6 minuti (5,83 + 0,25 = 6,08).

Facendo un rapido conto, considerando che i cicli sono 30 e che ad ogni passaggio ci sono 15 secondi di attesa, il tempo minimo necessario affinché tutte e 30 le celle dello Spreadsheet vengano valorizzate è di circa 7,5 minuti.
Il valore è stato calcolato moltiplicando il numero dei cicli per il numero di millisecondi di attesa ad ogni ciclo (15000) e dividendolo per 60000 millisecondi al fine di convertirlo in minuti: (30 * 15000)/60000 = 7,5.

Lo script che permette di completare le operazioni che in totale necessitano più di 6 minuti di esecuzione è realizzabile con una struttura simile alla seguente:

function testSolution() {
  var start = (new Date()).getTime(); // tempo di avvio dello script
  const MAX_RUNNING_TIME = 300000; // 5 minuti (limite di esecuzione manuale, per stare entro i 6 minuti)
  const TIME_TO_WAIT_FOR_TRIGGER_ATTIVATION = 120000; // 2 minuti (tempo di attivazione del trigger)
  var cache = CacheService.getScriptCache(); // inizializza la cache per gestire l'ultima iterazione
  var cached_i = cache.get("last_i"); // recupera dalla cache l'eventuale ultimo valore di iterazione
  if (cached_i == null) { cached_i = 1; } // se non c'è un'iterazione la inizializza
  var max_cells = 30; // numero massimo di iterazioni (cicli) impostato
  for (i=cached_i; i<=max_cells; i++) { // effettua n cicli dal valore dell'ultima iterazione fino al massimo indicato
    var lap = (new Date()).getTime(); // tempo di esecuzione dello script ad ogni ciclo
    if(lap - start >= MAX_RUNNING_TIME) { // se la differenza tra il tempo di inizio e quello attuale supera i 5 minuti impostati
      cache.put("last_i", i, 1800); // salva il valore dell'attuale iterazione in cache per 30 minuti
      // crea un trigger basato sul tempo con data e ora specifica (momento attuale + 2 minuti) per rieseguire la funzione
      ScriptApp.newTrigger("testSolution").timeBased().at(new Date(lap+TIME_TO_WAIT_FOR_TRIGGER_ATTIVATION)).create();
      break; // esce dal loop
    } else { // se la differenza tra il tempo di inizio e quello attuale è inferiore ai 5 minuti impostati
      // svolge le operazioni effettive dello script
      // INSERIRE QUI LE OPERAZIONI DELLO SCRIPT
    }
  }
  if (i >= max_cells) { cache.remove('last_i'); } // se il numero i cicli totali è stato raggiunto pulisce la cache
}

Nel dettaglio, viene salvato in una variabile il tempo al momento di avvio dello script, con le variabili MAX_RUNNING_TIME e TIME_TO_WAIT_FOR_TRIGGER_ATTIVATION sono indicati, rispettivamente, i tempi di esecuzione massima continua dello script (impostato manualmente a 300000 ms, ovvero 5 minuti, per essere sicuri di stare entro i 6 minuti consentiti) ed il tempo di attivazione del trigger (impostato a 120000 ms, ovvero 2 minuti, per assicurarsi che ci sia il tempo minimo per la generazione del trigger e successiva sua attivazione per rieseguire la funzione). Tra le inizializzazioni c'è quella del Servizio Cache (a tale scopo può essere utile la lettura dell'articolo 'Memorizzare le risorse nella Cache e condividerle tra un'esecuzione e l'altra') necessario per recuperare il valore dell'ultima iterazione (il numero di n cicli raggiunto entro il MAX_RUNNING_TIME) e per salvarlo al suo interno. E' definito inoltre il numero di cicli totali (in uno script effettivo sarà un valore calcolato sull'esigenza del momento in base alla lunghezza dell'eventuale array).
A questo punto si entra all'interno del loop e, per ogni ciclo, viene recuperato il valore del tempo in quel momento e calcolato, per differenza con il tempo di inizializzazione dello script, il tempo totale di esecuzione in quel momento. Se tale differenza è inferiore al valore di MAX_RUNNING_TIME vengono eseguite le normali operazioni dello script, altrimenti se tale valore è superato, viene salvato in cache il valore numerico dell'ultima iterazione del ciclo (per un tempo stabilito, nel caso specifico ho inserito 1800 secondi, ovvero 30 minuti, per stare sul sicuro ma è un tempo certamente sovrastimato), in modo che alla prossima esecuzione della funzione il ciclo riparta da quel valore e non dall'inizio, dopodiché viene creato un trigger basato sul tempo con data e ora specifica (basata sul momento attuale di creazione + i 2 minuti relativi alla variabile TIME_TO_WAIT_FOR_TRIGGER_ATTIVATION) per rieseguire la funzione, ed esce dal loop.
Una volta che il trigger riattiva la funzione, le operazioni appena descritte vengono eseguite nuovamente con la differenza che il ciclo stavolta parte dall'ultimo valore di iterazione del ciclo (recuperato dalla cache) fino a completamento operazione dove, per pulizia del dato, svuota la cache una volta uscito dal loop.

Un esempio funzionante di utilizzo di tale codice basato sulla funzione vista in precedenza, che scriveva i valori nelle celle di uno Spreadsheet ma che generava l'errore dovuto al limite di tempo massimo di esecuzione consentito superato, è il seguente:

function testSolution() {
  const MAX_RUNNING_TIME = 300000; // 5 minuti (il limite massimo di esecuzione consentito è di 6 minuti)
  const TIME_TO_WAIT_FOR_TRIGGER_ATTIVATION = 120000; // 2 minuti (per dare tempo al trigger di riattivare la funzione)
  var sheet = SpreadsheetApp.getActive().getActiveSheet();
  var cache = CacheService.getScriptCache();
  var start = new Date().getTime();
  var start_firstTime = cache.get("start_firstTime");
  if (start_firstTime == null) {
    start_firstTime = new Date().getTime();
    sheet = SpreadsheetApp.getActive().getActiveSheet().clear();
  }
  var cached_i = cache.get("last_i");
  if (cached_i == null) { cached_i = 1; }
  var max_cells = 30;
  for (i=cached_i; i<=max_cells; i++) {
    var lap = new Date().getTime();
    if(lap - start >= MAX_RUNNING_TIME) {
      // mantengo i valori in cache per 30 minuti (per stare larghi, per farli ritrovare alla seconda esecuzione della funzione)
      cache.put("last_i", i, 1800);
      cache.put("start_firstTime", start_firstTime, 1800);
      ScriptApp.newTrigger("testSolution").timeBased().at(new Date(lap+TIME_TO_WAIT_FOR_TRIGGER_ATTIVATION)).create();
      break;
    } else {
      sheet.getRange(i, 1).setValue(i);
      Utilities.sleep(15000);
      SpreadsheetApp.flush();
      Logger.log("Tempo trascorso per la scrittura continua di " + i + " celle: " + (lap - start_firstTime));
    }
  }
  if (i >= max_cells) {
    cache.remove('last_i');
    cache.remove('start_firstTime');
    var stop = new Date().getTime();
    Logger.log("Tempo trascorso dalla prima esecuzione dello script: " + (stop - start_firstTime));
  }
}

Avviando manualmente lo script una sola volta, l'effettivo funzionamento è confermato dal completamento dell'operazione richiesta, Fig. 4:

Fig. 4 - Inserimento completato dei valori nello Spreadsheet

Quello che succede effettivamente dietro le quinte, è l'esecuzione del codice che scrive continuamente fino ad un certo valore all'interno delle celle dello Spreadsheet, nel caso specifico 20. Questo perchè, come si può osservare dal log in Fig. 5 (effettuato durante il runtime), il tempo trascorso dall'avvio dello script fino a quello del momento di scrittura della cella 20, è di circa 290000 ms (corrispondenti a 4,83 minuti). Sulla base dello stesso calcolo effettuato a inizio articolo, i successivi 15 secondi dello sleep (corrispondenti a 0,25 minuti) se sommati all'ultimo tempo rilevato superano i 5 minuti impostati nella variabile MAX_RUNNING_TIME (5,83 + 0,25 = 5,08).

Fig. 5 - Log della prima esecuzione dello script

Nel momento in cui lo script si rende conto che il suo tempo di esecuzione supera quello indicato nella variabile MAX_RUNNING_TIME, salva in cache il punto in cui è arrivato in quel momento (che nel caso specifico è il valore della variabile i) e istanzia un trigger in modo programmatico tramite la Classe ScriptApp di Apps Script.
Questo significa che il trigger creato si trova effettivamente in interfaccia, tant'è che nell'editor di script, alla voce di menu 'Modifica -> Trigger del progetto corrente', è possibile vedere la presenza del trigger che è stato creato da codice, Fig. 6:

Fig. 6 - Trigger basato sul tempo con data e ora specifica creato in modo programmatico

Raggiunto il momento per il quale è stato richiesto al trigger di eseguire la funzione, quest'ultima continuerà ad effettuare il suo lavoro partendo dall'ultimo ciclo in cui era rimasta fino a completamento delle operazioni, come osservabile nel file di log, Fig. 7:

Fig. 7 - Log della seconda ed ultima esecuzione dello script

Il tempo totale di esecuzione dello script, come indicato nel file di log, risulta essere di circa 570000 ms, dal quale vanno tolti i 120000 ms impostati manualmente per dare margine di azione al trigger, pertanto l'esecuzione effettiva è stata di circa 450000 ms che, convertito in minuti è pari 7,5 come precedentemente ipotizzato (ben 1,5 minuti oltre il limite massimo consentito da Apps Script).

Ricordo che in caso di esecuzione di script che impiegamo molto tempo per svolgere le operazioni assegnate, è bene tenere presente che i limiti di quota (visionabili dal link alla documentazione ufficiale indicato a inizio articolo) sono applicati, oltre alla singola esecuzione dello script, anche al tempo totale di esecuzione giornaliera.