1

I have a Google sheets add-on listed on the market. In most cases it works OK, but for something like 10% of the users I can see in the Log Explorer the following security Notice level entry:

{
  "insertId": "-95cptdf17zlkw",
  "jsonPayload": {
    "serviceContext": {
      "service": "AKfycbwdlQO2SpUoJE-rL-QMnni4dihrhsvrx16GwESJswoy8NA"
    },
    "message": "Authorisation is required to perform that action."
  },
  "resource": {
    "type": "app_script_function",
    "labels": {
      "project_id": "formula-tracer-side-bar",
      "invocation_type": "unknown",
      "function_name": "excuteUserRequest"
    }
  },
  "timestamp": "2022-05-17T15:56:10.170Z",
  "severity": "NOTICE",
  "labels": {
    "script.googleapis.com/process_id": "EAEA1GOyaeEOdACtJlc76JEW70I8J5yujif1YQ8poDnneE6Tlg85jwUqn_oSIWZygqSxQ6s6DPtMt4jkIVo6Ak-2W8lR0K6Eyldw8kTvxvn-dauNu4PbQ8cgbpvGcReRquwiaOeV-ZehZev1w-1gmujKdpnPk95NERrAmskkifGIhFhjfmKrcb_wIdJENMD_ww4kgZWxiMJ0VSmNsV-Qr2d_FFoek6tF09xXJMgtIHBVWLEG9aJrn7GLfOfebJqj4L_RXWu1xu4aSKFiayU-HcJH_8-Yuo8FSMyIeC_Qd",
    "script.googleapis.com/project_key": "Mzy7e87MSzO0enTUViEAdROLp-GB2FQma",
    "script.googleapis.com/deployment_id": "AKfycbwdlQO2SpUoJE-rL-QMnni4dihrhsvrx16GwESJswoy8NA"
  },
  "logName": "projects/formula-tracer-side-bar/logs/script.googleapis.com%2Fconsole_logs",
  "receiveTimestamp": "2022-05-17T15:56:10.579606416Z"
} 

Relevant add-on pseudo code:

Server

function onInstall() {
    onOpen();
}

//add menu items to spreadsheet
function onOpen() {
    let menu = SpreadsheetApp.getUi().createAddonMenu();
    menu.addItem('Show side bar', 'showSidebar');
    menu.addToUi();
}

// called by menu items
function showSidebar() {
    let template = HtmlService
            .createTemplateFromFile("sideBar");

    let htmlOutput = template.evaluate();

    htmlOutput.setTitle(getHTMLTitle());
  
    SpreadsheetApp.getUi().showSidebar(htmlOutput);
}

//called by client
function excuteUserRequest(param){
    
    console.info("excuteUserRequest",param);

    //handle client request
    processRequest()
}

Client

//client
window.onload = function(){
    /* do some html initializtions*/
    initPage();
 
    //call server when addon is launched
    sendRequest();
}

function sendRequest(){

    let param = getParam();
    //Call trace on server
    google.script.run
    .withSuccessHandler(onSuccessRequest)
    .withFailureHandler(onFailueRequest)
    .excuteUserRequest(param);
}
  1. The server call to excuteUserRequest in the client sendRequest() is missing permissions. Looks like that the user(s) is not recognized by google as the error entry (although is logger entry is Notice level) is missing the user_key information as in most log entries

  2. Add-on is listed and approved after it successfully passed the oAuth verification process. So as I can understand it - the user approved the required permissions the add-on asks while installing

  3. I can not reproduce this situation. I thought it might be something with the user permissions for the specific spreadsheet the user is using. However, when using spreadsheets with no edit permission, the Google Sheets extensions menu is disabled thus the addon can not be launched at all.

  4. this post looks similar (client call app script server function sometimes fails with missing authorization), but I do not really understand if it is actually triggered by the same cause and if so, what to do.
    Other posts (this one and this one) looks irrelevant as they refer executing app script function - not one called from client, suggesting to manually run the function in the script editor to get the relevant permissions.

some clarification:

  1. user_key like actually all log fields accept the jsonPayload.message are added to the log entry. for example - the following log entry is from within showSidebar() the one before the error message.

the log message is only "X.XXX@YYYY.com showSideBar count: 0"
where: X.XXX@YYYY.com is the user email added by the addon for any console.log().

all other log fields are added by google for each console.log(msg). this includes the user_key which is assigned by Google.

To shortly summarize:
So same user first call showSideBar() from the spreadsheet extensions menu. This works fine, but the second call triggered immediately fails.

{
  "insertId": "bxz0h0f1zmrbn",
  "jsonPayload": {
    "serviceContext": {
      "service": "XXX",
      "version": "27"
    },
    "message": "X.XXX@YYYY.com showSideBar  count: 0"
  },
  "resource": {
    "type": "app_script_function",
    "labels": {
      "function_name": "",
      "invocation_type": "menu",
      "project_id": "formula-tracer-side-bar"
    }
  },
  "timestamp": "2022-05-17T15:56:12.864Z",
  "severity": "INFO",
  "labels": {
    "script.googleapis.com/project_key": "AAA",
    "script.googleapis.com/process_id": "BBB",
    "script.googleapis.com/deployment_id": "CCC",
    "script.googleapis.com/user_key": "DDD"
  },
  "logName": "EEE",
  "receiveTimestamp": "2022-05-17T15:56:13.653216430Z"
}

Please advise

OJNSim
  • 736
  • 1
  • 6
  • 22
  • Does it always occur for the same users or is it arbitrary (e.g. for the same user sometimes it works, sometimes it does not)? Can you make any connection between thethe users for which it occurs (e.g.g the ones that installed your Addon before /after you implemented a modification)? – ziganotschka May 30 '22 at 07:17
  • @ziganotschka As indicated, the Authorization log entry is missing the user key information, meaning I can not 100% recognize / associate this message to specific user. I can only make an educated guess by analyzing the Google Cloud log files and a "private" log spreadsheet I am using to associate between the user and the message. All users, but one, tried once and never again. One user tried 2-3 times in a row, but got the same result. I can not make any connection between the users, and / or to specific code changes. – OJNSim May 30 '22 at 08:06
  • From your code I cannot see the contents of `getParams()` and/ or the part of your code where `user_key` is being retrieved. Indepent from this> Is the Add-on only being used by the suer who installed the Addon - the spreadsheet owner, or also other editors of the spreadsheet that do not have their installation. You might want to have a look at the [Authorization model and modes](https://developers.google.com/apps-script/add-ons/concepts/editor-auth-lifecycle#authorization_model). – ziganotschka May 30 '22 at 12:23
  • @ziganotschka 1. the pseudo code only aims to demonstrate the flow. Real code is complicated but also irrelevant as it is only local js/html tasks. The missing authorization refers calling the server function `executeUserRequest`, as you can see in the message log field `resource` shows. 2. `user_key` maybe I was not clear. I (addon) do not use it at all. Please see the update to the post (#5). I hope it is clearer – OJNSim May 30 '22 at 13:59

1 Answers1

1

I found the reason for that, and how to recreate it. There is actually a pretty old issue for that in issues tracker data base

This is happening whenever:

  1. A client is simultaneously logged in to multiple Google's accounts
  2. the current active account (e.g. Account1) is not the default one (e.g. Account2)

In this scenario the server call is performed under the authorization of Account2 even though the active account is Account1

This is actually happen with Google services themselves. for example: When trying to open the script editor from the spreadsheet.
You can see in the image that even though the spreadsheet is shared by document owner account Formula Tracer, with account Formula Analyzer (default account) with full permissions, trying to open the script editor under the authority of Formula Tracer (the owner and active account) fails.

enter image description here

In the question specific case

function sendRequest(){

    let param = getParam();
    //Call trace on server
    google.script.run
    .withSuccessHandler(onSuccessRequest)
    .withFailureHandler(onFailueRequest)
    .excuteUserRequest(param);
}

function onFailueRequest(error){

    
}

the failure handler onFailueRequest is called with one of the two error messages:

  • authorization is required to perform this action

  • We're sorry, a server error occurred while reading from storage. Error code PERMISSION_DENIED

Note:

  • The 2nd possible message is localized so is will come based on client language. only the suffix PERMISSION_DENIED is in English

  • The type of error parameter might be a string or Error object

OJNSim
  • 736
  • 1
  • 6
  • 22