Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[BUG] App Insights not auto-capturing from a Web Worker #1995

Closed
celluj34 opened this issue Feb 17, 2023 · 37 comments
Closed

[BUG] App Insights not auto-capturing from a Web Worker #1995

celluj34 opened this issue Feb 17, 2023 · 37 comments
Assignees
Labels
released - NPM service-worker Required to properly support service workers shared-worker
Milestone

Comments

@celluj34
Copy link

celluj34 commented Feb 17, 2023

Description/Screenshot

I am trying to auto-capture fetch calls from a shared web worker. I can manually track exceptions, but I don't want to manually track all of the request/response dependencies. I am using a SharedWorker (a regular Worker exhibits the same issue) using the Comlink library.

I've searched and read the other issues (#1149, #1264, #1436, #1483, and #1727). They are either fixed or don't apply to my situation, and the most recent one is now over a year old which has since been fixed.

Steps to Reproduce

  • Create a worker (either Shared or regular)
  • Instrument App Insights using the "npm-style" setup inside the worker
  • make a fetch call from the worker
  • see that it does not auto-track

Client Info

  • OS/Browser: Windows 10 / Firefox 110
  • SDK Version [e.g. 22]: @microsoft/applicationinsights-web: 2.8.10
  • How you initialized the SDK: npm

Expected behavior

App Insights should auto-capture request and response information.

Additional context
Add any other context about the problem here.

Here is my initialization code. If I try to call trackPageView like I have before, it throws an exception (but only when enableDebug or enableDebugExceptions is true).

  initialize = (config: AppConfig, userId: string, workbookName: string) => {
    this._workbookName = workbookName;

    if (!config.appInsightsConnectionString) {
      return;
    }

    // https://docs.microsoft.com/en-us/azure/azure-monitor/app/javascript#configuration
    const appInsights = new ApplicationInsights({
      config: {
        connectionString: config.appInsightsConnectionString, // use connection string instead of just key
        disableAjaxTracking: true, // we don't use ajax
        disableFetchTracking: false, // we do use fetch
        disableXhr: true, // don't use XMLHttpRequest
        enableCorsCorrelation: true, // correlate requests with backend requests
        maxAjaxCallsPerView: 0, //track ALL calls from a single page view
        // enableDebug: true,
        // enableDebugExceptions: true,
      },
    });

    appInsights.loadAppInsights();
    appInsights.setAuthenticatedUserContext(userId, null, true);
    appInsights.context.application.ver = config.version;

    //add extension data to each request
    appInsights.addTelemetryInitializer(this.setWorkbookName);

    this._appInsights = appInsights;
  };
@MSNev
Copy link
Collaborator

MSNev commented Feb 17, 2023

disableAjaxTracking disables ALL XHR and fetch interception and reporting -- remove or set to false (the default is false)
disableFetchTracking setting to false in the current release is not necessary as since 2.8.0 we changed the default to false
maxAjaxCallsPerView setting this to zero (0) has a similar effect as disableAjaxTracking, even if the XHR and/or fetch are tracked this is the maximum number of dependency requests that will be reported per page view, at zero (0) this means nothing will be sent. The default is 500.

Suggest that you use the following

// https://docs.microsoft.com/en-us/azure/azure-monitor/app/javascript#configuration
    const appInsights = new ApplicationInsights({
      config: {
        connectionString: config.appInsightsConnectionString, // use connection string instead of just key
        disableXhr: true, // don't use XMLHttpRequest
        enableCorsCorrelation: true, // correlate requests with backend requests
      },
    });

@celluj34
Copy link
Author

Thanks for the info. I tried it with your suggestion but still no auto-tracking. I then enabled the debug settings and there's nothing in the logs, info, warning, error, nothing, so if something's not setup correctly I can't tell what it is.

Side note, it's an interesting point about disableAjaxTracking. In our main-thread app insights, we do get all of our telemetry data even with that set, though we are exclusively using fetch.

@MSNev
Copy link
Collaborator

MSNev commented Feb 17, 2023

disableAjaxTracking that is interesting as you shouldn't, because we don't add the instrumentation hooks and for fetch if this is true. Maybe it has a typo or something??? Another possibility, are there any other components on the page that are loading an older (v1) version, which doesn't have this config -- just guessing on this one.

Hmm, sounds like either the SDK is not initializing, our hooked (instrumented) fetch is being overwritten and not call (with some sort of polyfill) or the framework your using is grabbing a reference to the global fetch reference before we effectively replace (wrap) it....

// Framework
let cachedFetch = fetch;

// Initialize Application Insights (which wraps fetch)
initialize(...);

// So now usages of 
fetch(...); // are reported

// not reported as this is still pointing to the original (real) implementation
cachedFetch(...); 

If this is occurring then possible ways to fix this would be

  • Somehow cause your framework to "re-cache" the fetch instance
  • Try and initialize ApplicationInsights first before the framework caches the instance
  • Before either the framework or ApplicationInsights is initialized use the InstrumentFunc to pre-wrap the fetch instance like this we don't even need to provide any of the callbacks. This works because when Applicationinsights hooks a function or prototype it "reuses" and previous hook definition so it doesn't replace the global referenced variable, so anyone who has a cached reference will continue to call the safe Instrumented value.
InstrumentFunc(globalThis, "fetch", {
  ns: "pre-rwrapped"
  // you don't need to provide an req or rsp callback functions
});

I guess another possibility is that we are replacing/wrapping window.fetch (for main window) but the global.fetch for enviroments that don't have access to the window by this helper (if) this is returning a different global instance (which I've not seen so far) then perhaps we are wrapping one instance but your code is using another.

@celluj34
Copy link
Author

celluj34 commented Feb 17, 2023

Is there a way to know definitively if fetch has been hooked after instrumentation? Any property or function that's been modified so I can check in the console?

@celluj34
Copy link
Author

Another possibility, are there any other components on the page that are loading an older (v1) version, which doesn't have this config -- just guessing on this one.

Not that I am aware of - none of our other dependencies should have app insights and they certainly shouldn't be instrumenting their own instance.

We aren't using any polyfills for XHR or fetch, we are using the browser-shipped global fetch function to make HTTP requests to our API. I'll try the cached/global version to see if they act differently.

@celluj34
Copy link
Author

Hmm, sounds like either the SDK is not initializing, our hooked (instrumented) fetch is being overwritten and not call (with some sort of polyfill) or the framework your using is grabbing a reference to the global fetch reference before we effectively replace (wrap) it....

I tried with both cached fetch and the version after loadAppInsights, neither of them were auto-tracked.

InstrumentFunc

I tried this too and still nothing. I see my manually-tracked exception, but no fetch calls.

Am I crazy??? Is there something I'm missing? I basically copied the setup code from the main thread to the worker. This is so strange.

@MSNev
Copy link
Collaborator

MSNev commented Feb 17, 2023

Is there a way to know definitively if fetch has been hooked after instrumentation? Any property or function that's been modified so I can check in the console?

Something like this should work

> JSON.stringify(fetch._aiHooks)
< '{"i":1,"n":"fetch","h":[{"id":0,"cbks":{"ns":["AIBaseCore7_2_8_10_87dAWP","ajax10_87dAWP"]}}]}'

@MSNev
Copy link
Collaborator

MSNev commented Feb 17, 2023

You could use the InstrumentFunc() to add you own req callback to log to the console to make sure that our instrumentation is being called. You will only see this on the Shared Worker console...

@MSNev
Copy link
Collaborator

MSNev commented Feb 17, 2023

This (should) be working, the next stop sounds like debugging into your worker and setting break points to ensure that the SDK is running the code we think it is, as it's sounding like it's not for some reason. I don't currently have cycles to try and repo locally, so atm it will probably be a few weeks before we can look into this more deeply.

@MSNev MSNev added investigation required Further investigation or discussions required service-worker Required to properly support service workers shared-worker labels Feb 17, 2023
@celluj34
Copy link
Author

Is there a way to know definitively if fetch has been hooked after instrumentation? Any property or function that's been modified so I can check in the console?

Something like this should work

> JSON.stringify(fetch._aiHooks)
< '{"i":1,"n":"fetch","h":[{"id":0,"cbks":{"ns":["AIBaseCore7_2_8_10_87dAWP","ajax10_87dAWP"]}}]}'

image

I even added all 4 funcs to InstrumentFunc, and my breakpoints weren't hit, and nothing logged from the worker, not even after trackException:

image

@MSNev
Copy link
Collaborator

MSNev commented Feb 17, 2023

Ok, lets enumerate all of them then, can you try the following you will not likely get all 4 of them from the worker, but this will tell us if any of them are hooked.

globalThis && JSON.stringify(globalThis.fetch._aiHooks);
self && JSON.stringify(self.fetch._aiHooks);
window && JSON.stringify(window.fetch._aiHooks);
global && JSON.stringify(global.fetch._aiHooks)

And then after this lets find out which one is the "default"

console.log(globalThis && globalThis.fetch === fetch ? "globalThis" : "-1");
console.log(self && self.fetch === fetch ? "self" : "-2");
console.log(window && window.fetch === fetch ? "window"  : "-3");
console.log(global && global.fetch === fetch ? "global" : "-4");

If we get a hit on the _aiHooks that doesn't match the first hist on the 2nd then we have our initial answer and a way to identify how to fix the issue.

If we get nothing, then we have another set of issues, either your code is not running and therefore the SDK is not getting initialized (this would include your InstrumentFunc call) OR (more likely) the runtime is not letting us "replace" (hook) the fetch function...

@celluj34
Copy link
Author

celluj34 commented Feb 17, 2023

None of the 4 have _aiHooks. Only globalThis and self exist; global and window don't (which makes sense according to info on workers).

I think I have it narrowed down to something in the _instrumentFetch method when instrumenting the AjaxMonitor plugin. The main thread version does have the _aiHooks after this point, whereas the worker does not. I am debugging both to figure out where the worker is failing to instrument.

Edit:

In InstrumentFunc(), calling _getOwner(), hasOwnProperty(globalThis, "fetch") returns false, and the fallback also returns false. So the Instrumenting is never succeeding.

@celluj34
Copy link
Author

I wonder if this is a problem with Comlink, or just with SharedWorkers. I'll try to test it without using Comlink and see if it works any differently - perhaps they're clobbering globalThis.

@MSNev
Copy link
Collaborator

MSNev commented Feb 17, 2023

In InstrumentFunc(), calling _getOwner(), hasOwnProperty(globalThis, "fetch") returns false, and the fallback also returns false. So the Instrumenting is never succeeding.

This might be the issue as there is a recent change in some browsers where we have to check the getOwnPropertyDescriptor (which we are doing in the beta which should be released shortly) -- but will need to check this specific case as perhaps we just need to fallback to a simple check so that any parent implementation is also identified)

@celluj34
Copy link
Author

Not sure if this helps, but using in does work:

image

@MSNev
Copy link
Collaborator

MSNev commented Feb 17, 2023

Can you also try Object.getOwnPropertyDescriptor(globalThis, "fetch"), if this returns true then the beta we work, if not then we need to update it as well.

@celluj34
Copy link
Author

Nope, it returns undefined.

@celluj34
Copy link
Author

I did actually try the latest beta but it did not work. I went back to latest stable before making the issue.

@MSNev
Copy link
Collaborator

MSNev commented Feb 17, 2023

Thanks for trying the beta -- apart from this issue, was there anything unexpected that occurred etc. I'm going to create another issue about adding "in" check to the Instrument code and I'll link to this issue.

@celluj34
Copy link
Author

I don't think there was anything else. I saw all of the manual events (Exceptions, Events, etc) just fine. It was only the auto-tracking that was not working. Thank you for taking the time to work with me! I hope to be able to try the beta (again) soon!

@celluj34
Copy link
Author

Potentially unrelated, when I call trackPageView from the worker version, it threw an exception when I had debugging enabled. Once this is fixed, will we still need to call that to "start" tracking? Without it, once we hit 500 calls, would that effectively block all subsequent tracking calls?

@MSNev MSNev added this to the 2.8.11 milestone Feb 17, 2023
@MSNev
Copy link
Collaborator

MSNev commented Feb 17, 2023

Yes, by default that would occur, however, if you set maxAjaxCallsPerView to -1 it basically says there is no limit 😃.
I've added this one to 2.8.11 as well so that this issue can track the page view exception.

I can feel a SharedWorker sample in my future.

@MSNev
Copy link
Collaborator

MSNev commented Feb 23, 2023

@celluj34

Potentially unrelated, when I call trackPageView from the worker version, it threw an exception when I had debugging enabled.

Do you have the exception for this, I've created a simple sample with this PR #1996, but the trackPageView() I'm doing in the worker is running fine...

@celluj34
Copy link
Author

celluj34 commented Feb 23, 2023

Sure thing:

Uncaught [object Object]{"messageId":37,"message":"AI (Internal): 37 message:\"trackPageView failed, page view will not be collected: \" props:\"{exception:[object String]\\[object Object]{\\\\\\messageId\\\\\\:25,\\\\\\message\\\\\\:\\\\\\AI (Internal): 25 message:\\\\\\\\\\\\\\trackPageView: navigation timing API used for calculation of page duration is not supported in this browser. This page view will be collected without duration and timing info.\\\\\\\\\\\\\\\\\\\\}\\}\""}
_self.throwInternal @ DiagnosticLogger.js:101
_throwInternal @ AnalyticsPlugin.js:641
_self.<computed> @ AnalyticsPlugin.js:202
eval @ HelperFuncs.js:641
eval @ VM178:1
initialize @ fetch.worker.ts:37
callback @ comlink.mjs:103

Keep in mind you do have to have the debug config settings enabled (I didn't check which one - I had them both set to true).

@MSNev
Copy link
Collaborator

MSNev commented Feb 24, 2023

Thanks, I obviously didn't drill down far enough when debugging the Shared Worker.
The PR mentioned is now checked into the beta branch and should cause a new beta release tonight (this won't fix the trackPageView, but the fetch should now work).

I'm now in the process of migrating this to master and I'll revisit the (and fix) the trackPageView issue and then migrate that fix back to beta

@MSNev
Copy link
Collaborator

MSNev commented Feb 24, 2023

The _getOwner() is effectivelly called recursively, where it tries to find the ultimate owner from the target instance so it effective "cycles" the checkPrototype and checkParentProto here https://github.com/microsoft/ApplicationInsights-JS/blob/beta/shared/AppInsightsCore/src/JavaScriptSDK/InstrumentHooks.ts#L140.

This is required because for a WebWorker it's not the current global but it's parent that "owns" the fetch

@celluj34
Copy link
Author

Oh, I see it now. I don't understand how it works, but I see that it does:

image

Although it's still not auto-tracking, that's probably related to trackPageView throwing an exception.

Thanks for getting that updated so quickly!

@MSNev
Copy link
Collaborator

MSNev commented Feb 24, 2023

Ok, I've got the migrated code working in 2.8.x and I've tracked down the "exception" for the trackPageView. And it's not actually an exception, as the page view event is still sent.
However, we call throwInternal here to indicate that we can't emit a page view performance event (for every page view -- which seem excessive).

So I'll look at either reducing this to once or just disable when running in a web worker. I'm now going to check if the max ajax counts are reset and if not I'll fix that also for this case.

@MSNev
Copy link
Collaborator

MSNev commented Feb 24, 2023

We should be good on the max ajax calls -- they look like the count is getting reset here

@celluj34
Copy link
Author

Great, thanks for the info! I still worry that even though AI has been instrumented, it's for some reason still not auto-tracking. I didn't see anything being sent to my azure instance in the network logs.

To be more precise, according to the docs, I need to call trackPageView to "start" the tracking of calls made on a page. I don't actually care about any timing info, but if I omit that call, does that mean AI will never auto-track fetch? Since it's exiting early, is that blocking AI somehow?

@MSNev
Copy link
Collaborator

MSNev commented Feb 24, 2023

I need to call trackPageView to "start" the tracking of calls made on a page.

No this is not necessary, it's just generally the first thing most people want to do for their page and as soon as the page is "operational". Its also (by default) not triggered (and won't be for a WebWorker) from the URL location change.

if I omit that call, does that mean AI will never auto-track fetch?

No, as soon as you call "initialize" and it's successful (doesn't fail for some reason) all automatic tracking (fetch in this case)

Since it's exiting early, is that blocking AI somehow?

No, but by default events are batched and only sent every 15 seconds, you can change this with the maxBatchInterval configuration.

Also, instrumenting the "worker" will NOT instrument the main page as they operate in different runtimes and do not share the fetch instance. So (just in case you or anyone else reading this later), if you want to have both the worker and main page instrumented then both need to initialize their own SDK instances.

@celluj34
Copy link
Author

No this is not necessary, it's just generally the first thing most people want to do for their page and as soon as the page is "operational". Its also (by default) not triggered (and won't be for a WebWorker) from the URL location change.

Ah, makes sense!

if you want to have both the worker and main page instrumented then both need to initialize their own SDK instances.

Yep, this makes total sense. In our case we're funneling ALL fetch calls through the worker so this won't apply to us, but is a good note for future readers!

So it sounds like this should be working, but I'm not seeing any Dependency data in the track call to AI, only my manually-logged Exception (I did remove the trackPageView call):

image

I don't suppose you have any other handy tips? 😅

@MSNev
Copy link
Collaborator

MSNev commented Feb 27, 2023

I just checked with the SharedWorker example that I created and it is reporting the remote dependencies
image

So with the beta it should be working, the above was collected via my 2.8.x PR #2001 for migrating this to master and fixing (stopping) the trackPageView warning on web workers.

MSNev added a commit that referenced this issue Feb 28, 2023
…#2001)

- Merge from `beta` [BUG] SharedWorker does not Instrument fetch
correctly #1996
- [BUG] App Insights not auto-capturing from a Web Worker #1995
@celluj34
Copy link
Author

Not sure what I was missing the other day, but yep I confirm it's working!

image

I am on the latest beta though so once stable is released I'll move back to that (unless it's already updated).

@MSNev
Copy link
Collaborator

MSNev commented Feb 28, 2023

Last nights nightly release for 2.8.11 (2302-05) includes both of the "fixes" (fetch monitoring in the web worker and suppression of the page view performance message). The plan is to create the 2.8.11 release either later this week or early next (for npm).

For the beta, I'm currently merging the suppression back to beta and the plan is to start promoting the beta to v3.x by the end of March.

Copy link

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Mar 16, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
released - NPM service-worker Required to properly support service workers shared-worker
Projects
None yet
Development

No branches or pull requests

2 participants