Application Insights errors

[tgoyer]

Prerequisites

Node: v12.16.3

Current behavior

When developing an Excel add-in, office-addin-debugging continuously throws the following exceptions:

ApplicationInsights:Sender [
  'Ingestion endpoint could not be reached 20 consecutive times. There may be resulting telemetry loss. Most recent error:',
  Error: socket hang up
      at connResetException (internal/errors.js:608:14)
      at Socket.socketOnEnd (_http_client.js:453:23)
      at Socket.emit (events.js:322:22)
      at endReadableNT (_stream_readable.js:1187:12)
      at processTicksAndRejections (internal/process/task_queues.js:84:21) {
    code: 'ECONNRESET'
  }
]

ApplicationInsights:Sender [
  'Not saving data due to max size limit being met. Directory size in bytes is: 50000175'
]

Is there any way to either disable Application Insights or squelch this error? In addition, what directory is the error message referring to? I have not been able to find any documentation on these issues.

[ChrisRomp]

Supposedly running npx office-addin-usage-data off suppresses telemetry but I'm still getting a similar timeout error even after doing that and restarting my shell.

[TCourtneyOwen]

Sorry to hear you are having problems. Which version of the office-addin-debugging package are you running in your project? If you want to try suppressing the AppInsights calls you can go to node_modules\office-addin-debugging\lib and search for instances of "sendUsageDataSuccessEvent" - there's one in start.js and one in stop.js - and comment them out. Obviously that's not an ideal solution but this may help you get up and running and help us isolate if it's the calls to sendUsageDataSuccessEvent that are problematic.

Please let me know if this helps.

Thanks,

Courtney

[tgoyer]

@TCourtneyOwen I'm running the version that comes by default in the yo generator-office command. From the package.json: "office-addin-debugging": "^3.0.25"

I commented these lines out and I still get the same error.

start.js

            ...
            console.log(enableDebugging
                ? "Debugging started."
                : "Started.");
-->          //defaults_1.usageDataObject.sendUsageDataSuccessEvent("startDebugging");
        }
        catch (err) {
-->         //defaults_1.usageDataObject.sendUsageDataException("startDebugging", err);
            throw err;
        }

stop.js

            ...
            console.log("Debugging has been stopped.");
-->         //defaults_1.usageDataObject.sendUsageDataSuccessEvent("stopDebugging");
        }
        catch (err) {
-->         //defaults_1.usageDataObject.sendUsageDataException("stopDebugging", err);
            throw err;
        }

[tgoyer]

@TCourtneyOwen It's might also be helpful to know that, because of my industry, our traffic to the internet is greatly restricted by firewall rules. Is this trying to call home to a Microsoft internal ApplicationInsights server that I am unaware of? If so, what exactly is it capturing? This could be problematic...

[TCourtneyOwen]

@tgoyer Yes data is sent to Azure ApplicationInsights to gather exception data, whether a particular method succeed and the add-in project attributes such as host type and framework (e.g. React, Angular).

Can you please try the following:

• if you are on Windows, open %\Users\<User_Name\office-addin-usage-data.json in notepad. You should see something like the following:

{ "usageDataInstances": { "office-addin-usage-data": { "usageDataLevel": "on" } } }

Set the usageDataLevel to off and save the file. This should ensure that all calls to send usage data to Application Insights are by passed.

[tgoyer]

@TCourtneyOwen Hi again!

I made the change to the JSON file and restarted the debugger:

{
  "usageDataInstances": {
    "office-addin-usage-data": {
      "usageDataLevel": "off"
    }
  }
}

... and I'm still getting these errors:

ApplicationInsights:CorrelationIdManager [
  Error: socket hang up
      at connResetException (internal/errors.js:608:14)
      at Socket.socketOnEnd (_http_client.js:453:23)
      at Socket.emit (events.js:322:22)
      at endReadableNT (_stream_readable.js:1187:12)
      at processTicksAndRejections (internal/process/task_queues.js:84:21) {
    code: 'ECONNRESET'
  }
]
ApplicationInsights:Sender [
  'Not saving data due to max size limit being met. Directory size in bytes is: 50000175'
]

On my second point above, is the behavior opt-in? I don't recall a question about this during the template generation. I don't like the idea of potentially sensitive sources and uses information being silently logged by a third-party. We both know that stuff leaks into exception logs. That is what I find problematic about this whole issue. If we didn't have our firewall locked down, we wouldn't even be aware this is happening. Sorry to bust your chops about this. But at least let us have the option to say no.

[ChrisRomp]

@tgoyer The first time I ran yo office notified me about telemetry, gave me the npx office-addin-usage-data off command, and presented me with the option to continue or exit. But that's the only time it does it. It's on by default.

I'm also working in an environment with restrictive firewalls (and no local admin, which is making this difficult in other ways).

[tgoyer]

@ChrisRomp That's my point. It should be off by default with the option to turn it on and it should ask every time.

[ChrisRomp]

Wishful thinking. ;)

(I'm agreeing with you.)

[tgoyer]

@ChrisRomp Like it or not, Office is the toolkit for business, especially Excel (where I am getting this issue from). Businesses don't like their trade secrets getting leaked. If Microsoft wants to continue to repair their relationship with business developers and security officers, they need to do better. Stuff like this is why no one likes Google.

[TCourtneyOwen]

The behavior is opt-out, meaning you are opted in and have the option to opt out by running the aforementioned command npx office-addin-usage-data off You should have seen this message the first time you created a project with Yo Office. It's possible you just skipped through it. We had quite a bit of discussion internally about the opt-in vs opt-out model. Looping in the PM for this @JuaneloJuanelo to provide his comments.

I am not sure why you are still encountering issues when collection of usage data is set to off. I will need to debug the code locally and see if I can figure out what the problem is. It's possible that this flag is not getting respected for some reason or in some cases.

Are you confident this error is coming from the office-addin-debugging package? It could also perhaps be coming from office-addin-manifest office-addin-dev-settings.

[tgoyer]

@TCourtneyOwen I don't know. I sent you all the error information I have. It even continues even after I stop debugging.

This is currently in my console:

> office-addin-taskpane-js@0.0.1 stop C:\_git\addin
> office-addin-debugging stop manifest.xml

Debugging is being stopped...
Stopped dev server. Process id: 12548
Debugging has been stopped.
ApplicationInsights:CorrelationIdManager [
  Error: socket hang up
      at connResetException (internal/errors.js:608:14)
      at Socket.socketOnEnd (_http_client.js:453:23)
      at Socket.emit (events.js:322:22)
      at endReadableNT (_stream_readable.js:1187:12)
      at processTicksAndRejections (internal/process/task_queues.js:84:21) {
    code: 'ECONNRESET'
  }
]
ApplicationInsights:Sender [
  'Not saving data due to max size limit being met. Directory size in bytes is: 50000175'
]
ApplicationInsights:Sender [
  'Not saving data due to max size limit being met. Directory size in bytes is: 50000175'
]

I get that every 30-60 seconds, it seems.

[TCourtneyOwen]

Yeah it could be any of the packages I mentioned but they should all be checking the usage data setting in office-addin-usage-data.json I mentioned. I need to look at this closer. Perhaps it just the instantiation of the usage data object that's leading to the problem. The calls for sending usage data may in fact not occur and are respecting the "off" flag but the instantiation of the object may make a call to AppInsights as well

[tgoyer]

@TCourtneyOwen What directory is it referring to? Perhaps there is a log in there that might shed some light?

[TCourtneyOwen]

My guess is that the call to appInsights.setup in office-addin-usage-data package is the problem. You can see the code here at line 97: https://github.com/OfficeDev/Office-Addin-Scripts/blob/master/packages/office-addin-usage-data/src/usageData.ts

[TCourtneyOwen]

Did you use Yo Office to create your projects? The reason I ask is that Yo Office uses that same office-addin-usage-data package to send telemetry and I can't understand why you wouldn't encounter problems as well during project creation

[tgoyer]

@TCourtneyOwen Yes. I followed the directions outlined in this tutorial:

https://docs.microsoft.com/en-us/office/dev/add-ins/quickstarts/excel-quickstart-jquery?tabs=yeomangenerator

I used the Yeoman Generator workflow since I prefer to do my Javascript work in VSCode. I may try again using Visual Studio 2019 and see if I get a better outcome.

[TCourtneyOwen]

I am trying to figure out the ports AppInights uses to send data so I can block them myself locally to help get a repro. I will let you know what I find.

[TCourtneyOwen]

OK, I have a repro here that shows when blocking port 443 for outgoing traffic on my local machine I get a similar error that you get, so somewhere along the way we either aren't respecting the "off" flag in office-addin-usage-data or an issue is occurring at the instantiation of the usage data object. This should be helpful in further debugging the issue

[tgoyer]

@TCourtneyOwen, any progress with this? I think it might also be spawning rogue Node zombie processes. It seems like I have to reboot my computer regularly to get the debug webserver to restart. When that happens, I usually have a dozen or more Node processes running in Task Manager even through I only have VSCode running.

Running npm run stop doesn't seem to help.

[TCourtneyOwen]

@tgoyer Sorry I haven't had a chance to do further investigation on this. But tomorrow is our weekly bug fix day, so I will make this my top priority and keep you posted what I find.

Thanks,

Courtney

[TCourtneyOwen]

@tgoyer I think I figured out the fix for this. The problem is this code in the constructor for office-addin-usage-data:

    appInsights.setup(this.options.instrumentationKey)
      .setAutoCollectExceptions(false)
      .start();
    this.usageDataClient = appInsights.defaultClient;
    this.removeApplicationInsightsSensitiveInformation();

We call the setup method method for appInsights, which makes and https call, even if office-addin-usage-data is set to off.

This should fix the problem, I verified locally:

  if (this.options.usageDataLevel === "on") {
    appInsights.setup(this.options.instrumentationKey)
      .setAutoCollectExceptions(false)
      .start();
    this.usageDataClient = appInsights.defaultClient;
    this.removeApplicationInsightsSensitiveInformation();
  }

I will create a PR for this and add you to it

[TCourtneyOwen]

@tgoyer Here's the PR for this fix: https://github.com/OfficeDev/Office-Addin-Scripts/pull/304

[TCourtneyOwen]

@tgoyer I published out a new version of office-addin-usage-data that has the fix. Can you please try running "npm ci" in your project directory to pick up the latest version and then try your scenario again?

[tgoyer]

EDIT: I noticed that my package.json may be loading an older version of the office addins. I am going to manually bump the versions and see if it helps.

@TCourtneyOwen Thanks for looking into this. I am still getting this error even after updating node modules:

ApplicationInsights:CorrelationIdManager [
  Error: socket hang up
      at connResetException (internal/errors.js:608:14)
      at Socket.socketOnEnd (_http_client.js:453:23)
      at Socket.emit (events.js:322:22)
      at endReadableNT (_stream_readable.js:1187:12)
      at processTicksAndRejections (internal/process/task_queues.js:84:21) {
    code: 'ECONNRESET'
  }
]
ApplicationInsights:Sender [
  'Ingestion endpoint could not be reached 5 consecutive times. There may be resulting telemetry loss. Most recent error:',
  Error: socket hang up
      at connResetException (internal/errors.js:608:14)
      at Socket.socketOnEnd (_http_client.js:453:23)
      at Socket.emit (events.js:322:22)
      at endReadableNT (_stream_readable.js:1187:12)
      at processTicksAndRejections (internal/process/task_queues.js:84:21) {
    code: 'ECONNRESET'
  }
]

Here is the package.json of the office-addin-usage-data package that npm ci installed to verify that I got the right version:

{
  "name": "office-addin-usage-data",
  "version": "1.1.4",
  "description": "Provides infrastructure to send usage data events and exceptions.",
  "main": "./lib/main.js",
  "scripts": {
    "build": "rimraf lib && concurrently \"tsc -p tsconfig.json\"",
    "cli": "node lib/cli.js",
    "test": "mocha -r ts-node/register test/**/*.ts",
    "watch": "rimraf lib && concurrently \"tsc -p tsconfig.json -w\""
  },
  "author": "Office Dev",
  "license": "MIT",
  "bin": {
    "office-addin-usage-data": "./cli.js"
  },
  "keywords": [
    "Office",
    "Office Add-in"
  ],
  "dependencies": {
    "applicationinsights": "^1.7.3",
    "commander": "^2.20.3",
    "office-addin-cli": "^0.2.8",
    "readline-sync": "^1.4.9"
  },
  "devDependencies": {
    "@types/applicationinsights": "^0.20.0",
    "@types/es6-promise": "3.3.0",
    "@types/mocha": "^5.2.7",
    "@types/node": "^12.12.34",
    "concurrently": "^5.2.0",
    "mocha": "^7.1.1",
    "rimraf": "^2.6.3",
    "ts-node": "^8.8.1",
    "tslint": "^6.1.0",
    "typescript": "^3.8.3"
  },
  "repository": {
    "type": "git",
    "url": "https://github.com/OfficeDev/Office-Addin-Scripts"
  },
  "bugs": {
    "url": "https://github.com/OfficeDev/Office-Addin-Scripts/issues"
  },
  "gitHead": "b8541cdb1fe826f2edcc5215c565d7b4cde7c1a7"

,"_resolved": "https://registry.npmjs.org/office-addin-usage-data/-/office-addin-usage-data-1.1.4.tgz"
,"_integrity": "sha512-k2jhtK5lVdrgcXmtnf5KJxtw3ZeUwEZGYcV6+j5ZaZSNbtDxppC+s4j28j4Lhi0D66QSWepBw1d36j9Acqwdpw=="
,"_from": "office-addin-usage-data@1.1.4"
}

[tgoyer]

@TCourtneyOwen Ok, after deleting my package-lock.json and manually bumping the package.json versions, I now see office-addin-usage-data v1.1.6 in node-modules and I have verified that your fix exists in the usageData.ts file.

I'll run this and see if I get a better result. I'll update in a bit...

[TCourtneyOwen]

I think our publishing process failed last night, although there were no conspicuous errors that indicated that. I just published a new version a few minutes ago - the latest version if 1.1.16. The 1.1.14 version of office-addin-usage-data does not contain the fix. Can you please try updating the version to 1.1.16 and see if that fixes it for you?

[tgoyer]

@TCourtneyOwen I think the fix you made has resolved the issue I was experiencing and I'm not seeing any more rogue Node processes as well. Thanks for the assistance!

If I see anything else, I'll be sure to let you know.

Feel free to close this issue. If I find anything else, I'll raise a new one.

[TCourtneyOwen]

That's fantastic! Glad to hear it!