Bug 685945 - Sync: log a warning if JSON parsing of bodies fails. r=philikon

services/sync/modules/resource.js

@@ -387,7 +387,18 @@ AsyncResource.prototype = {
     // Make a lazy getter to convert the json response into an object.
     // Note that this can cause a parse error to be thrown far away from the
     // actual fetch, so be warned!
-    XPCOMUtils.defineLazyGetter(ret, "obj", function() JSON.parse(ret));
+    XPCOMUtils.defineLazyGetter(ret, "obj", function() {
+      try {
+        return JSON.parse(ret);
+      } catch (ex) {
+        this._log.warn("Got exception parsing response body: \"" + Utils.exceptionStr(ex));
+        // Stringify to avoid possibly printing non-printable characters.
+        this._log.debug("Parse fail: Response body starts: \"" +
+                        JSON.stringify((ret + "").slice(0, 100)) +
+                        "\".");
+        throw ex;
+      }
+    }.bind(this));
 
     this._callback(null, ret);
   },

services/sync/tests/unit/test_resource.js

@@ -175,8 +175,18 @@ function run_test() {
   // res.data has been updated with the result from the request
   do_check_eq(res.data, content);
 
+  // Observe logging messages.
+  let logger = res._log;
+  let dbg    = logger.debug;
+  let debugMessages = [];
+  logger.debug = function (msg) {
+    debugMessages.push(msg);
+    dbg.call(this, msg);
+  }
+
   // Since we didn't receive proper JSON data, accessing content.obj
-  // will result in a SyntaxError from JSON.parse
+  // will result in a SyntaxError from JSON.parse.
+  // Furthermore, we'll have logged.
   let didThrow = false;
   try {
     content.obj;
@@ -184,6 +194,10 @@ function run_test() {
     didThrow = true;
   }
   do_check_true(didThrow);
+  do_check_eq(debugMessages.length, 1);
+  do_check_eq(debugMessages[0],
+              "Parse fail: Response body starts: \"This path exists\".");
+  logger.debug = dbg;
 
   _("Test that the BasicAuthenticator doesn't screw up header case.");
   let res1 = new Resource("http://localhost:8080/foo");

services/sync/tests/unit/test_resource_async.js

@@ -189,6 +189,15 @@ add_test(function test_get() {
     // res.data has been updated with the result from the request
     do_check_eq(res.data, content);
 
+    // Observe logging messages.
+    let logger = res._log;
+    let dbg    = logger.debug;
+    let debugMessages = [];
+    logger.debug = function (msg) {
+      debugMessages.push(msg);
+      dbg.call(this, msg);
+    }
+
     // Since we didn't receive proper JSON data, accessing content.obj
     // will result in a SyntaxError from JSON.parse
     let didThrow = false;
@@ -198,6 +207,10 @@ add_test(function test_get() {
       didThrow = true;
     }
     do_check_true(didThrow);
+    do_check_eq(debugMessages.length, 1);
+    do_check_eq(debugMessages[0],
+                "Parse fail: Response body starts: \"This path exists\".");
+    logger.debug = dbg;
 
     run_next_test();
   });