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.

Sign up for GitHub

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

Log when respecting the Do-Not-Track header #48

Closed
wants to merge 4 commits into from
Closed

Log when respecting the Do-Not-Track header #48

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
689b7bf
Log when respecting the Do-Not-Track header
ExplodingCabbage Sep 11, 2021
a99525c
Update src/messages.js
ExplodingCabbage Sep 13, 2021
496d970
Fix syntax error
ExplodingCabbage Sep 13, 2021
88c0548
Test that we only warn about do-not-track once
ExplodingCabbage Sep 13, 2021
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions src/__tests__/LDClient-events-test.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -274,6 +274,7 @@ describe('LDClient events', () => {
await client.identify(user1);

expect(ep.events.length).toEqual(0);
expect(platform.testing.logger.output.warn).toEqual([messages.doNotTrackEnabled()])
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

There's a failing GitHub check because this is missing a trailing semi-colon.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actually, rather than adding an assertion to this existing test case, it would be preferable to have a new test case. That way we can trigger multiple events and additionally verify that the Do-Not-Track message is only logged once.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That way we can trigger multiple events and additionally verify that the Do-Not-Track message is only logged once.

Makes sense.

it would be preferable to have a new test case.

Hmm. Thing is, this test case would basically be a copy-and-paste of the existing test case but with extra lines. If one test is going to basically be a subset of the other, it probably makes sense to just have the larger one?

With that in mind I've extended the existing test case to make a second .identify call and then check that the logger output is unchanged.

Possibly we've got slightly different philosophies about test suite design and this won't seem like the right solution to you; if so, feel free to tweak as you see fit! "Allow edits by maintainers" is switched on. :)

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, this very well could be due to slight differences in test philosophies. The perspective I'm coming from is that, in the case that the test fails, I want the test name to denote what went wrong. That wouldn't be the case here -- we'd be testing the behavior of the logging, rather than that the SDK "does not send an identify event if doNotTrack is set". Also the behavior we're testing isn't specific to identify events -- for example we also have a test in this file to verify that track events aren't sent if Do-Not-Track is enabled.

As for the copy-paste concern, the test case I'm thinking of is slightly different -- effectively we'd have two calls to generate events before making any assertions.. For example, two client.identify calls, or maybe one client.identify and one client.track, followed by just a single assertion for the single logged message.

});
});
});
Expand Down
13 changes: 12 additions & 1 deletion src/index.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -61,6 +61,7 @@ export function initialize(env, user, specifiedOptions, platform, extraOptionDef
let inited = false;
let closed = false;
let firstEvent = true;
let hasLoggedDntWarning = false;

// The "stateProvider" object is used in the Electron SDK, to allow one client instance to take partial
// control of another. If present, it has the following contract:
Expand Down Expand Up @@ -118,7 +119,17 @@ export function initialize(env, user, specifiedOptions, platform, extraOptionDef
}

function shouldEnqueueEvent() {
return sendEvents && !closed && !platform.isDoNotTrack();
if (!sendEvents || closed) {
return false;
}
if (platform.isDoNotTrack()) {
if (!hasLoggedDntWarning) {
logger.warn(messages.doNotTrackEnabled());
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not sure that we want to log at the warning-level here -- this message is primarily intended for developers as opposed to end-users, and yet it is equally likely that end users will encounter the message. End users shouldn't have the noise of seeing this warning on websites using LaunchDarkly.

My preference would be to lower this to a debug-level log. I expect that this would have been sufficient to save you and your colleague your lost time -- do you agree?

Suggested change
logger.warn(messages.doNotTrackEnabled());
logger.debug(messages.doNotTrackEnabled());

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hmm. No, I don't think this makes sense:

  • Debug-level logs are invisible in the Chrome console by default; you have to enable "verbose" mode from a little dropdown at the top of the console to be able to see them
  • I think the logger you create in the JS client SDK gets created with a max level of "info" and so if you change this to .debug it won't actually log anything at all

I'm not sure the developers vs end users distinction makes much sense to me either. Anyone opening the console and looking at what's been logged can basically be presumed to be a developer, no? Or at least, if they're a real user, they've made a deliberate choice to pop open the dev tools and look under the hood. It's not like the logger is going to put these messages onto the page.

Finally, some other messages that feel similar in character to this one (like "localStorage is unavailable") already get logged at .warn level, so using .warn here seems consistent with the precedent you've got for when to use which log levels.

Copy link
Contributor

@eli-darkly eli-darkly Sep 13, 2021 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think the logger you create in the JS client SDK gets created with a max level of "info" and so if you change this to .debug it won't actually log anything at all

The default logger that you get if you don't customize anything has a level of "info", but you can customize that. The intention is that if a developer is trying to investigate some unexpected behavior and wants to see detailed logging, they would set it to "debug". That's the reason such a method as .debug() exists— we didn't implement it to be just a no-op.

This particular message does seem to me like something we would not want to emit by default, because it's not of any possible use to a regular user— that is, they already know that they turned on do-not-track, and it would just be saying that it is behaving as expected. The "localStorage is unavailable" message is different, because there it is saying the SDK functionality is unable to work as desired.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I realize that from the developer's point of view, the distinction I'm making there is not so clear, because analytics events are a thing you want to be able to use and they're being blocked. But the effect of that is only visible on the back end— it doesn't have any effect on the user's experience, whereas local storage being disabled potentially does have a noticeable effect (long load times due to no caching). Maybe I am splitting hairs, but that's the thinking that was behind the warn level there.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

As for whether "anyone opening the console and looking at what's been logged can basically be presumed to be a developer"— the concern with appropriateness of warn logging isn't that the log would disrupt anything for normal users, but simply that if someone who does know how to use the console gets curious and looks at the log, something that looks like a warning message may give an misleading sense of something being broken. I would be fine with this being either info or debug, but some browsers (such as Chrome) will show warn messages in a style that connotes "potential problem, please pay attention to this" and that's really not applicable in this case. I presume in this particular case you would have noticed an info message in the console too.

Copy link
Author

@ExplodingCabbage ExplodingCabbage Sep 13, 2021 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The default logger that you get if you don't customize anything has a level of "info", but you can customize that. The intention is that if a developer is trying to investigate some unexpected behavior and wants to see detailed logging, they would set it to "debug".

Okay, but that's still requiring additional reading and debugging effort from a dev who's trying to get started. I don't think I even realised that enabling more verbose logging was possible prior to it coming up here, and it would've been (and was) low on my list of ideas to try when observing .identify calls not triggering requests. Also, I don't think it's covered outside of the API docs currently, which is a long way to stray for someone who's trying to follow the Getting Started guide or fiddling with the existing LaunchDarkly integration in their company's website for the first time and wondering why it's not working in their dev environment. Perhaps you've got a better gauge of it than I do, but I would be surprised if more than a tiny minority of users of the SDK have ever tweaked the logger config to aid their debugging.

It seems much friendlier to just put the explanation for why stuff doesn't work right there in the console for them, without them having to put in extra effort to solicit debugging information. I'd expect to need to enable debug logging if I wanted to see minutiae like every event and every flag evaluation being logged, but a big slice of the SDK's functionality being disabled doesn't feel like a debug-level event to me.

it's not of any possible use to a regular user

I still don't get this - what do we mean by a regular user here and why is such a person looking in the console in the first place?

they already know that they turned on do-not-track

You'd think so, but this isn't a safe assumption. Neither I nor my colleague knew; in both cases it was turned on by privacy plugins we'd installed in our browser, rather than due to us specifically enabling it in our browser settings. Also, even if they know it's turned on, they don't necessarily know LaunchDarkly respects it.

The "localStorage is unavailable" message is different, because there it is saying the SDK functionality is unable to work as desired.

To my mind these are similar; in both cases, the SDK is running in an environment where some of its functionality is disabled, and so in both cases it makes sense to emit a warning so that when we're in a dev environment the developer sees that some functionality is turned off and why.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I presume in this particular case you would have noticed an info message in the console too.

Yes, this would work - but I think, actually, that the default logger level is warn rather than info as I had previously stated... so I think making this info-level would again hit the problem that it's not logged by default.

Copy link
Contributor

@eli-darkly eli-darkly Sep 13, 2021 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sorry, my mistake - the default level in this case is indeed warn. It is info for most of our SDKs, but it's deliberately higher for the browser for the reasons I stated. I'm going to defer to the rest of the team when it comes to further discussion of what is or is not reasonable to show by default.

About the documentation, though— I agree that the docs should say more about logging, since https://docs.launchdarkly.com/sdk/client-side/javascript doesn't currently have a section for logging as the other SDKs do.

However, in terms of documentation specifically about do-not-track— that same page does have a warning callout that says:

Do Not Track and ad blocking software
The JavaScript SDK respects the Do Not Track events header. If an end-user has Do Not Track enabled in their browser, the SDK does not send analytics events for flag evaluations or goals. In addition, ad-blocking software may block analytics events from being sent. This does not impact feature flag evaluations.

You wouldn't see that if you were only looking at the very basic Getting Started section, but the same is true of lots of areas of SDK functionality. Each SDK has a main docs page like this, which highlights some important points and then links to more detailed information on each feature as well as to the API docs.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah -- all in all let's change this to an info-level message. @ExplodingCabbage

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Well, I can't stop you, and you're welcome to take over the PR and implement what you like. I'm not going to do it myself because IMO it renders the whole PR more or less pointless.

hasLoggedDntWarning = true;
}
return false;
}
return true;
}

function enqueueEvent(event) {
Expand Down
4 changes: 4 additions & 0 deletions src/messages.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -110,6 +110,10 @@ export const identifyDisabled = function() {
return 'identify() has no effect here; it must be called on the main client instance';
};

export const doNotTrackEnabled = function() {
return 'Not sending events to LaunchDarkly because Do Not Track is enabled.';
ExplodingCabbage marked this conversation as resolved.
Show resolved Hide resolved
};

export const streamClosing = function() {
return 'Closing stream connection';
};
Expand Down