microsoft
trackTrace model being manipulated to invalid
Hello,
We have used AppInsights JS SDK for quite a while now (currently on v2.7.2). Recently we noticed in our logs we were not receiving everything we're sending. Upon inspection it appears that sometimes when we use trackTrace the simple object of message (string), properties (object), and severityLevel (number) is being malformed and is causing the request to come over as an object instead.
While this is not according to spec it also does not always complain about this. Sometimes the message as an object is allowed and other times a 400 error is thrown. I have checked all of our code and we are passing a string for the message and an object for properties to the AppInsights JS SDK. This means something in the SDK is somtimes malforming the message to be an object with a message and properties property in it. Below are some example requests that are sent to the SDK as well as what the SDK sends to the server and what the server sends back:
Example 1: Requests submitted to SDK:
{
message: "modules/a-module.connect() id=asdf-asdf-asdf-asdf",
properties: {
simulated: "false"
},
severityLevel: null
}
{
message: "modules/a-module.discoveryResult() devices(s)",
properties: [
0: {
label: "Device A",
status: "online"
},
1: {
label: "Device B",
status: "offline"
},
],
severityLevel: null
}
Request submitted to server from SDK (removing some properties for brevity):
[
0: {
data: {
baseData: {
message: "modules/a-module.connect() id=asdf-asdf-asdf-asdf",
properties: {
simulated: "false"
},
ver: 2
},
baseType: "MessageData"
}
},
1: {
data: {
baseData: {
message: {
message: "modules/a-module.discoveryResult() devices(s)",
properties: [
0: {
label: "Device A",
status: "online"
},
1: {
label: "Device B",
status: "offline"
},
],
severityLevel: null
},
properties: {},
ver: 2
},
baseType: "MessageData"
}
}
]
Note that in the above the first instance is correct (message is a string, properties is an object) and the server accepts it. In the second instance we have a malformed request now where message is now an object with properties message (string), properties (object), and severityLevel (number). The server still accepts this request and I can see both of these in the logs. Also to note is the first example does not have severityLevel in the SDK request but the second one does. In both instances our code sent a null for severityLevel.
Response from server:
{
errors: {},
itemsAccepted: 2,
itemsReceived: 2
}
Example 2: Requests submitted to SDK:
{
message: "modules/a-module.selectDevice()",
properties: {
label: "Device A",
status: "online"
},
severityLevel: null
}
Request submitted to server from SDK (removing some properties for brevity):
[
0: {
data: {
baseData: {
message: {
message: "modules/a-module.selectDevice()",
properties: [
0: {
label: "Device A",
status: "online"
}
],
severityLevel: null
},
properties: {},
ver: 2
},
baseType: "MessageData"
}
}
]
In the above in this example it's the same as the second request in the first example in terms of structure where message is not a string as it should be but rather an object with properties of message (string), properties (object), and severityLevel (number). Unlike the first example though, this rejected by the server and we cannot see it in the logs.
Response from server:
{
errors: [{
0: {
index: 0,
message: "106: Field 'message' on type 'MessageData' is of incorrect type. Expected: string, Actual: [object Object]",
statusCode: 400
}
}],
itemsAccepted: 0,
itemsReceived: 1
}
There appears to be some issue within the SDK that is sometimes malforming the message to include other things like properties. This is causing the server to receive an object instead of a string. Additionally the server only sometimes rejects the malformed message object as bad. This is causing us to be partially blind into the actions the code is taking when there are issues. Our code only passes an object with properties message (string), properties (object), and severityLevel (number) to the trackTrace method. However for some reason sometimes the request the SDK sends to the server is correct and sometimes it is not. Likewise sometimes the server accepts the incorrect message object and other times rejects it.
I don't think this is a specific issue within the SDK, but rather I suspect it's an issue caused by either the way you are creating and passing the arguments to traceTrace or some additional plugin in your environment that is doing something strange with strings and the usage of JSON.stringify().
Very Simplistically, for this case of traceTrace apart from "copying" (assigning object properties via effectively foreach (x in y) { evt.data[x] = y; }) fields into the "acceptable" form by the server follows this up by serializing via JSON.stringify() and this is what is passed to the server, so the invalid format is then driven by the input.
- An immediate observation is that you appear to be passing properties as an array
- it MUST be an object which has strings as the keys of the fields and while it takes 'any' as a value when an object they should be correctly formed and should only include serializable (via JSON.stringify) values and this will fail if you have circular references.
We have also noticed recently that sometime JavaScript doesn't always do what you expect for example try this in your browsers console
let value = 2; { data: { value } } results in { data: { value: 2 } }
while
{ data: { 2 } } results in 2
So one results in an object while the 2nd results in a number.
Can you please try your examples in your environment and dump them using JSON.stringify() to review the results. For reference this is the code that "transforms" the provided values into the final outgoing message https://github.com/microsoft/ApplicationInsights-JS/blob/master/shared/AppInsightsCommon/src/TelemetryItemCreator.ts#L20-L61
Hi,
Thanks for the response. I've tested by taking the custom properties entirely out of the request being sent and am still getting an issue. Also the documentation located at https://github.com/microsoft/ApplicationInsights-JS/blob/master/API-reference.md references an object of message (string), properties? (object), and severityLevel? (number) but if I look at the code here https://github.com/microsoft/ApplicationInsights-JS/blob/37739711b264903d7efa04e8514b6ea263e63c62/shared/AppInsightsCommon/src/Interfaces/IAppInsights.ts it references a trace (ITraceTelemetry) that is an object of message (string), severityLevel (SeverityLevel), and iKey (SeverityLevel). Is the API documentation wrong? The below request/response is using the NEW details located in the code and not the documentation.
Here's the breakdown:
Request sent to the SDK:
{
message: "modules/a-module.connectResult() error",
severityLevel: null
}
Request sent from the SDK to the server:
[
0: {
data: {
baseData: {
message: {
message: "modules/a-module.connectResult() error",
severityLevel: null
},
properties: {},
ver: 2
},
baseType: "MessageData"
}
}
]
Response from the server:
{
errors: [{
0: {
index: 0,
message: "106: Field 'message' on type 'MessageData' is of incorrect type. Expected: string, Actual: [object Object]",
statusCode: 400
}
}],
itemsAccepted: 0,
itemsReceived: 1
}
Given that I am not passing any custom properties that need to be serialized I do not believe this to be a serialization issue.
Adding another piece if data here. In the console if I execute window.appInsights.trackTrace({ message: "test" }); the message payload is an object instead of a string and I receive the same 400 error.
Hi @bgp1, It's actually more nuanced than (is the API correct or not) because it both is and is not correct -- let me explain.
Because of history there is actually 2 different API surfaces (v1 and v2) and depending on "how" you initialize the SDK determines which "version" is exposed so the traceTrace can be either trackTrace(message: string, properties?: { [name: string]: string; }, severityLevel?: any) (V1) or trackTrace(trace: ITraceTelemetry, customProperties?: ICustomProperties) (v2) where the v1 "maps" the request to a v2 ITraceTelemetry object and then calls that version.
Based on the passed message getting converted to
message: { message: "modules/a-module.connectResult() error", severityLevel: null }
This looks like your exposed instance (API surface) is actually using the V1 method.
So how does this happen and how do you fix. Using the snippet: (I suspect you are using this)
- If you load the SDK from the CDN via the snippet, when using the original legacy snippet (V1) this will cause the SDK to expose the
ApplicationInsightsDeprecated(v1) as to try and maintain backward compatibility for people upgrading to the new v2 code. - This can be "fixed" by changing the snippet included on your page to the latest, which also includes a bunch of additional functionality.
If your using NPM
- When you call
appInsights.loadAppInsights()the first optional argumentlegacyMode(defaults to false) if this is passed as true you will get the v1 API surface and if not you get v2.
I am using npm and using v2 of the interface. Here is my init code:
import { ApplicationInsights } from '@microsoft/applicationinsights-web';
const appInsights = new ApplicationInsights({ config: {
autoTrackPageVisitTime: true,
instrumentationKey: isProduction ? settings.keys.production : settings.keys.staging
}});
appInsights.loadAppInsights();
window.appInsights = appInsights;
That should give you the v2 and therefore the trackTrace(trace: ITraceTelemetry, customProperties?: ICustomProperties) which is basically the same as the https://github.com/microsoft/ApplicationInsights-JS/blob/master/API-reference.md (the extra customProperties if supplied get merged into the generated ITraceTelemetry)
I'll have to dig into this a bit deeper I think -- it will probably be a few days before i can spend a decent amount of time on this, I'll respond once I've had a chance
Ok, I think something really weird is going on with the version you are using...
I just created a local test using (mostly) your exact data and the formatted and sent values to the server are exactly what is expected.
appInsights.trackTrace({
message: "modules/a-module.connect() id=asdf-asdf-asdf-asdf",
properties: {
simulated: "false"
},
severityLevel: null
});
appInsights.trackTrace({
message: "modules/a-module.discoveryResult() devices(s)",
properties: [
{
label: "Device A",
status: "online"
},
{
label: "Device B",
status: "offline"
},
],
severityLevel: null
});
appInsights.trackTrace({
message: "modules/a-module.discoveryResult() devices(s)",
properties: {
0: {
label: "Device A",
status: "online"
},
1: {
label: "Device B",
status: "offline"
},
},
severityLevel: null
});
Note: passing properties both as a valid array and as an object with "array" keyed elements
Results (only copied the data node)
{
"baseType": "MessageData",
"baseData": {
"ver": 2,
"message": "modules/a-module.connect() id=asdf-asdf-asdf-asdf",
"properties": {
"simulated": "false"
}
}
}
{
"baseType": "MessageData",
"baseData": {
"ver": 2,
"message": "modules/a-module.discoveryResult() devices(s)",
"properties": {
"0": "{\"label\":\"Device A\",\"status\":\"online\"}",
"1": "{\"label\":\"Device B\",\"status\":\"offline\"}"
}
}
}
{
"baseType": "MessageData",
"baseData": {
"ver": 2,
"message": "modules/a-module.discoveryResult() devices(s)",
"properties": {
"0": "{\"label\":\"Device A\",\"status\":\"online\"}",
"1": "{\"label\":\"Device B\",\"status\":\"offline\"}"
}
}
}
And the server response
{"itemsReceived":3,"itemsAccepted":3,"errors":[],"appId":"739f4637-8979-4944-9650-99b82a3d4ed6"}
And in all 3 cases the null Severity level was removed as the formatting removes "empty" values.
So from this my observations and questions are mostly the same as before as it looks like you are using the v1 API of trackTrace, but even with that it doesn't explain the presence of the ```null`` SeverityLevel as this should be getting removed.
- Can you please check the version of the SDK being used (this will also appear in the outbound request
ai.internal.sdkVersion: javascript:2.7.2) - Is it possible that another SDK is loading in your environment (perhaps via an old snippet) -- potentially auto injected (depending how you app is hosted) which is overriding the global
appInsightsvariable (this gets rooted on window by default -- so same aswindows.appInsights.- This might explain the sometimes situation
- Do you have a repro site that I could try and debug, as this looks like it's potentially not something "simple"?
- An unminified version would be ideal, but sometime with the map files for the AI code would work as well.
Thanks for the response. I've been investigating since your reply and I think you may be on to something. We do inject a snippet in our views from the Microsoft.ApplicationInsights.AspNetCore (v2.19.0) Nuget package. Looking at the specific calls that are failing the initiator is not our JS file but the page itself (the snippet) and have the following SDK in the request ai.internal.sdkVersion: "javascript:snippet_4". If I remove the injection in our views it appears all requests work and all come from our JS file instead. Will test this solution more thoroughly over the next few days but this might be the cause.
Given the Nuget package is v2 perhaps the bug is actually in the injectable from the Nuget package instead.
I'll let you know once we're able to test this more to confirm.
Thanks for standing by. We've been in production with these changes for several days now and can confirm we are receiving all logging messages now vs before when it was only some. Removing the injected script from our views using the Nuget package was the issue causing the conflict.
This Issue will be closed in 30 days. Please remove the "Stale" label or comment to avoid closure with no action.
![github-actions[bot] avatar](https://avatars.githubusercontent.com/in/15368?v=4 "Published by a pub.dev verified publisher"){kind=small}
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.