821877 - The logging added to CSP in bug 783049 needs to go to the web console instead of the error console

Status: VERIFIED FIXED

(Core :: Security, defect, P1)

Description

[Ian Melven :imelven]

In bug 783049 we do logging when we see the to-be-deprecated, prefixed  CSP header or when we see both headers and will ignore the to-be-deprecated, prefixed CSP header. The patches in that bug log to the error console, we strongly want logging to the web console instead but don't want to hold up our spec compliant CSP stuff landing for that.

The sticking point here is that we don't have a window ID associated with the document being loaded when we're in InitCSP(). 

Discussed with Mihai and have some ideas but this needs more work.

Comment 1

[Garrett Robinson [:grobinson]]

Adding Mihai so I can ask him about the Web Console :)

Comment 2

[Garrett Robinson [:grobinson]]

Hey Boris! I added you to this bug to ask for a sanity check on the design I'm considering.

Our problem is that we want to log CSP errors to the Web Console, but some of the errors are triggered around nsDocument::StartDocumentLoad, before nsDocShell::SetupNewViewer (which sets the InnerWindowID that we need to log to the Web Console). The errors that this bug addresses are in InitCSP, which is called at the end of StartDocumentLoad.

My idea is to create a temporary queue for CSP errors on the nsDocument object, and log any errors there until we've setup the document viewer and associated web console. At this point, we can flush the queue to the web console, and log any subsequent errors normally.

What do you think about this idea? Sane, or is there something better that I've missed? Thanks!

Comment 3

[Boris Zbarsky [:bzbarsky]]

How do we manage to do this for necko notifications for the document channel?  Or do we not show those in the web console until after the new document is set up?

Comment 4

[Garrett Robinson [:grobinson]]

They don't show in the web console unless the console is activated (unlike CSS or JS errors, for example). Verify by opening any URL and opening the web console. You may see CS, JS, or Logging errors, but you won't see any requests. Refresh the page (with the web console now active) and they will appear.

This is because the NetworkMonitor is implemented in chrome js (WebConsoleUtils.jsm) and so is necessarily attached to a window. You can see how the ActivitySubtype functions all query the current window (getWindowForRequest) and don't log anything (return null) if they can't find it.

Comment 5

[Boris Zbarsky [:bzbarsky]]

Ah, I see.

Yeah, queuing things up on the nsDocument seems fine.

Comment 6

[Garrett Robinson [:grobinson]]

Attachment: Patch 1

Log errors from nsDocument::InitCSP to Web Console
    
Since InitCSP is run before the window is created, we queue all errors from CSP code on nsDocument and flush them to the Web Console once the window has been created.

My main remaining questions are:

1. Is this the recommended way to do memory management for elements of the list? I see it also used in netwerk/dns/DNS.cpp:196 for example.
2. The end of nsHTMLDocument::EndLoad is probably not he best place to flush the error queue to the Web Console. Perhaps nsDocument::EndLoad? Or elsewhere?

Comment 7

[Ian Melven :imelven]

Comment on attachment 731303 [details] [diff] [review]
Patch 1

Review of attachment 731303 [details] [diff] [review]:
-----------------------------------------------------------------

Overall, looks like a great first pass at this. 

You'll want to put the bug # (and probably the description of the bug) in your patch title (using hg qref -e for example if you're using mq)

You'll need to edit the patch title as well before pushing to mark who the reviewer was, too - e.g. "Bug 123456 - fix blah blah r=reviewer" - there's a hook that checks for a
reviewer on pushes.

::: content/base/src/nsDocument.cpp
@@ +2515,4 @@
>                                      "CSP", this,
>                                      nsContentUtils::eDOM_PROPERTIES,
>                                      "OldCSPHeaderDeprecated");
> +    // additionally log deprecated warning to Web Console

nit: Capitalize and use punctuation in comments (i know this isn't done everywhere.. )

::: content/base/src/nsDocument.h
@@ +1,2 @@
>  /* -*- Mode: C++; tab-width: 2; indent-tabs-mode: nil; c-basic-offset: 2 -*- */
> +/* vim: set sw=2 ts=2 et tw=80: */

probably don't want to add this

@@ +466,5 @@
>    bool mHaveShutDown;
>  };
>  
> +class CSPErrorQueueElement
> +: public mozilla::LinkedListElement<CSPErrorQueueElement>

please follow the same formatting here as other classes in nsDocument.h (looks to me like this should all be on the same line)

@@ +470,5 @@
> +: public mozilla::LinkedListElement<CSPErrorQueueElement>
> +{
> +  public:
> +    const char* mMessageName;
> +

In general it looks like we put methods before members

@@ +472,5 @@
> +  public:
> +    const char* mMessageName;
> +
> +    CSPErrorQueueElement(const char* aMessageName)
> +      : mMessageName(aMessageName)

based on rest of file, formatting looks like it should be : 

 CSPErrorQueueElement(const char* aMessageName) :
   mMessageName(aMessageName)

You're doing a shallow copy of the string ID that's passed in (copying the pointer, not the actual string data) - will it always be true that the string won't go out of scope and be freed before you process the queue ?

@@ +473,5 @@
> +    const char* mMessageName;
> +
> +    CSPErrorQueueElement(const char* aMessageName)
> +      : mMessageName(aMessageName)
> +    {}

also looks like these should be on separate lines

@@ +475,5 @@
> +    CSPErrorQueueElement(const char* aMessageName)
> +      : mMessageName(aMessageName)
> +    {}
> +
> +    ~CSPErrorQueueElement() {}

see above, this should probably be separated into 3 lines

@@ +481,5 @@
> +
> +class CSPErrorQueue
> +{
> +  private:
> +    mozilla::LinkedList<CSPErrorQueueElement> mQueue;

see above re methods before members

@@ +494,5 @@
> +        CSPErrorQueueElement* error = mQueue.popFirst();
> +        nsContentUtils::ReportToConsole(nsIScriptError::warningFlag,
> +            "CSP", aDocument,
> +            nsContentUtils::eDOM_PROPERTIES,
> +            error->mMessageName);

usually these line up with the first argument, i.e
"CSP" should line up under nsIScriptError::warningFlag

@@ +502,5 @@
> +
> +    ~CSPErrorQueue()
> +    {
> +      // If the queue was never flushed, make sure it's cleared
> +      //mQueue.clear();

remove commented out things please (also it looks like the comment is no longer true and should be removed?)

@@ +504,5 @@
> +    {
> +      // If the queue was never flushed, make sure it's cleared
> +      //mQueue.clear();
> +      CSPErrorQueueElement* element;
> +      while ((element = mQueue.popFirst()))

extra parens ?

@@ +1467,4 @@
>    nsrefcnt mStackRefCnt;
>    bool mNeedsReleaseAfterStackRefCntRelease;
>  
> +  //friend class CSPErrorQueue;

remove commented out things please

::: content/html/document/src/nsHTMLDocument.cpp
@@ +923,4 @@
>    if (turnOnEditing) {
>      EditingStateChanged();
>    }
> +  nsDocument::flushCSPWebConsoleErrorQueue();

yeah, let's see what Boris says about where to do this :)

Comment 8

[Boris Zbarsky [:bzbarsky]]

How long a list are we typically expecting here?  Do we have any idea at all?

The right place to flush things to the console is probably SetScriptGlobalObject, since that's where we get told what our window is.

Comment 9

[Garrett Robinson [:grobinson]]

(In reply to Boris Zbarsky (:bz) from comment #8)
> How long a list are we typically expecting here?  Do we have any idea at all?
> 

The length would at most be the maximum number of user-facing errors logged in nsDocument::InitCSP. At the moment, this is 3 (count the number of calls to nsContentUtils::ReportToConsole).

> The right place to flush things to the console is probably
> SetScriptGlobalObject, since that's where we get told what our window is.

Awesome! I've implemented this change. I foolishly pulled from master, so my build is taking a very long time. I will add the patch as soon as I have verified the build with this change (plus imelven's style fixes).

Comment 10

[Boris Zbarsky [:bzbarsky]]

> At the moment, this is 3

Then how about we just use an auto array of size 5 or something and not worry about all the linked list complexity and heap-allocation?

Comment 11

[Garrett Robinson [:grobinson]]

Attachment: Patch 2

This patch incorpoates all of bz and imelven's feedback.

1. Made the stylistic changes (both coding style and patch style) suggested by imelven
2. Moved the call to flush the error queue to SetScriptGlobalObject
3. Use an nsAutoTArray instead of a LinkedList to store the errors (since there is a fixed maximum number of errors that we expect to encounter in InitCSP)

Comment 12

[Boris Zbarsky [:bzbarsky]]

Comment on attachment 732590 [details] [diff] [review]
Patch 2

>+#include "mozilla/LinkedList.h"

No longer needed, both places.

>+++ b/content/base/src/nsDocument.cpp
>+  flushCSPWebConsoleErrorQueue();

Capital 'F', please.

>+++ b/content/base/src/nsDocument.h
>+#include "nsContentUtils.h"

I would vastly prefer not having to include that here, since it pulls in the world, and instead just not making the methods on CSPErrorQueue inline.

Doubly so if you're going to use PR_LOG in them, because the definition of that macro will depend on other headers and defines and whatnot, and you _really_ don't want to have to worry about the ordering on that sort of thing.

Is there a reason gCspErrorQueuePRLog is not a class static?

>+    void add(const char* aMessageName) {

Again, local style is that class methods typically have a capital first letter.

Document that this function does NOT take ownership of the passed-in string data; it's the caller's responsibility to make sure it never dies.

>+    ~CSPErrorQueue() {

The nsTArray destructor will clear the array; no need to manually clear it.

>+  void flushCSPWebConsoleErrorQueue()

This shouldn't be public.  It also shouldn't be after the data members, but before them, with other protected or private methods

Comment 13

[Garrett Robinson [:grobinson]]

Attachment: Patch 3

This patch resolves the issues from bz's latest review.

1. Removed obsolete includes
2. Code style
3. Move Add and Flush function definitions to nsDocument.cpp to avoid including nsIContentUtils.h

After consulting with imelven, we agreed that logging overflow on the auto array was overkill and I have removed it.

Comment 14

[Garrett Robinson [:grobinson]]

Attachment: Test 1

Browser mochitest that tests if a warning about using deprecated CSP headers is logged to the Web Console when a page serving these deprecated headers is loaded.

Comment 15

[Boris Zbarsky [:bzbarsky]]

Comment on attachment 733469 [details] [diff] [review]
Patch 3

>+void CSPErrorQueue::Add(const char* aMessageName) {

File style would be:

 void
 CSPErrorQueue::Add(const char* aMessageName)
 {

Comment 16

[Boris Zbarsky [:bzbarsky]]

Comment on attachment 733469 [details] [diff] [review]
Patch 3

r=me modulo the style nit.

Comment 17

[Garrett Robinson [:grobinson]]

Attachment: Patch 4

Fix style nit from bz's last review. Carrying over r+ from bz.

Comment 18

[Mihai Sucan [:msucan]]

Comment on attachment 733470 [details] [diff] [review]
Test 1

Review of attachment 733470 [details] [diff] [review]:
-----------------------------------------------------------------

Test looks good, but I do get a failure:

TEST-UNEXPECTED-FAIL | chrome://mochitests/content/browser/browser/devtools/webconsole/test/browser_webconsole_bug_821877_csp_errors.js | Timed out while waiting for: CSP error displayed successfully

Also check the comments below:

::: browser/devtools/webconsole/test/Makefile.in
@@ +213,5 @@
>  	test-repeated-messages.html \
>  	test-bug-766001-console-log.js \
>  	test-bug-766001-js-console-links.html \
>  	test-bug-766001-js-errors.js \
> +	browser_webconsole_bug_821877_csp_errors.js \

Please move this new webconsole test up in the file, in the list of browser chrome tests.

::: browser/devtools/webconsole/test/browser_webconsole_bug_821877_csp_errors.js
@@ +11,5 @@
> +    openConsole(null, function testCSPErrorLogged (hud) {
> +      var outputNode = hud.outputNode;
> +      waitForSuccess({
> +        name: "CSP error displayed successfully",
> +        timeout: 5000,

You do not need to change th timeout. 5000 ms is the default.

::: browser/devtools/webconsole/test/test-bug-821877-csperrors.html
@@ +1,3 @@
> +<!doctype html>
> +<html>
> +  <head>

Please add a <meta charset="utf8"> to avoid a warning about missing charset.

Comment 19

[Garrett Robinson [:grobinson]]

Attachment: Test 2

Incorporate msucan's suggestions and ideas from IRC. I never experienced a test failure here while he did - hopefully these changes make sure this test will pass. The failure may have been due to logging another error caused by the lack of a <meta charset> tag in the dummy HTML document.

Comment 20

[Garrett Robinson [:grobinson]]

Attachment: Test 3

This patch fixes another CSP browser chrome test (for 770099) that was broken by my patch (discovered during a try run). The 770099 test uses the deprecated headers, and assumed that only one warning will be logged to the Web Console. I have rewritten the test to correctly check for the full CSP violation error regardless of the number of warnings logged.

Comment 21

[Mihai Sucan [:msucan]]

Comment on attachment 733983 [details] [diff] [review]
Test 3

Review of attachment 733983 [details] [diff] [review]:
-----------------------------------------------------------------

This works for me now.

Please make sure you add the public domain license header to the new tests (csp_errors.js and .html). See http://www.mozilla.org/MPL/headers/ - you do not need to ask for review again.

Thanks!

Comment 22

[Garrett Robinson [:grobinson]]

Attachment: Test 4

Add public domain license to .js and .html in the Mochitest. Carrying over r+ from msucan.

Comment 23

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/7c6c85096304
https://hg.mozilla.org/integration/mozilla-inbound/rev/beb76e040390

Comment 24

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/7c6c85096304
https://hg.mozilla.org/mozilla-central/rev/beb76e040390

Comment 25

[Garrett Robinson [:grobinson]]

This patch landed with the assumption that we would be able to get the CSP 1.0 implementation completed and flip the pref to turn it on by default in time for mozilla23. This did not happen (progress is being tracked in Bug 842657). The result is that this warning message advises developers to use the unprefixed Content-Security-Policy header, which is silently ignored (http://mxr.mozilla.org/mozilla-central/source/content/base/src/nsDocument.cpp#2463) if the pref is not set. This is bad advice and we need to back out the patch until the pref is set so it is not telling people to do the wrong thing.

Comment 26

[Boris Zbarsky [:bzbarsky]]

Fwiw, the right way to do that is to leave this bug fixed until the backout happens, so that there is a separate bug tracking the backout that can have the appropriate tracking and approval cruft and whatnot....

Comment 27

[Lukas Blakk [:lsblakk] use ?needinfo]

please mark status 23 disabled once the backout in bug 873187 lands

Comment 28

[Ryan VanderMeulen [:RyanVM]]

Backed out from Fx23 in bug 873187.
https://hg.mozilla.org/releases/mozilla-aurora/rev/7c7e6e87fe76

Comment 29

[Garrett Robinson [:grobinson]]

This patch was returned to firefox23 by Bug 878790 after a brief backout. Closing again as resolved/fixed.

Comment 30

[Matt Wobensmith [:mwobensmith][:matt:]]

Verified FF24 2013-09-10.