Bug 1103958 - Dumping Gecko AppInfos and about:memory in LogShake. r=gwagner

b2g/components/LogCapture.jsm

@@ -4,15 +4,23 @@
 /* jshint moz: true */
 /* global Uint8Array, Components, dump */
 
-'use strict';
+"use strict";
 
-this.EXPORTED_SYMBOLS = ['LogCapture'];
+const Cu = Components.utils;
+const Ci = Components.interfaces;
+const Cc = Components.classes;
+
+Cu.import("resource://gre/modules/XPCOMUtils.jsm");
+
+XPCOMUtils.defineLazyModuleGetter(this, "Promise", "resource://gre/modules/Promise.jsm");
+
+this.EXPORTED_SYMBOLS = ["LogCapture"];
 
 const SYSTEM_PROPERTY_KEY_MAX = 32;
 const SYSTEM_PROPERTY_VALUE_MAX = 92;
 
 function debug(msg) {
-  dump('LogCapture.jsm: ' + msg + '\n');
+  dump("LogCapture.jsm: " + msg + "\n");
 }
 
 let LogCapture = {
@@ -24,11 +32,11 @@ let LogCapture = {
 
   load: function() {
     // load in everything on first use
-    Components.utils.import('resource://gre/modules/ctypes.jsm', this);
+    Cu.import("resource://gre/modules/ctypes.jsm", this);
 
-    this.libc = this.ctypes.open(this.ctypes.libraryName('c'));
+    this.libc = this.ctypes.open(this.ctypes.libraryName("c"));
 
-    this.read = this.libc.declare('read',
+    this.read = this.libc.declare("read",
       this.ctypes.default_abi,
       this.ctypes.int,       // bytes read (out)
       this.ctypes.int,       // file descriptor (in)
@@ -36,19 +44,24 @@ let LogCapture = {
       this.ctypes.size_t     // size_t size of buffer (in)
     );
 
-    this.open = this.libc.declare('open',
+    this.open = this.libc.declare("open",
       this.ctypes.default_abi,
       this.ctypes.int,      // file descriptor (returned)
       this.ctypes.char.ptr, // path
       this.ctypes.int       // flags
     );
 
-    this.close = this.libc.declare('close',
+    this.close = this.libc.declare("close",
       this.ctypes.default_abi,
       this.ctypes.int, // error code (returned)
       this.ctypes.int  // file descriptor
     );
 
+    this.getpid = this.libc.declare("getpid",
+      this.ctypes.default_abi,
+      this.ctypes.int  // PID
+    );
+
     this.property_find_nth =
       this.libc.declare("__system_property_find_nth",
                         this.ctypes.default_abi,
@@ -153,6 +166,26 @@ let LogCapture = {
     }
 
     return propertyDict;
+  },
+
+  /**
+   * Dumping about:memory to a file in /data/local/tmp/, returning a Promise.
+   * Will be resolved with the dumped file name.
+   */
+  readAboutMemory: function() {
+    this.ensureLoaded();
+    let deferred = Promise.defer();
+
+    // Perform the dump
+    let dumper = Cc["@mozilla.org/memory-info-dumper;1"]
+                    .getService(Ci.nsIMemoryInfoDumper);
+
+    let file = "/data/local/tmp/logshake-about_memory-" + this.getpid() + ".json.gz";
+    dumper.dumpMemoryReportsToNamedFile(file, function() {
+      deferred.resolve(file);
+    }, null, false);
+
+    return deferred.promise;
   }
 };
 

b2g/components/LogShake.jsm

@@ -21,32 +21,32 @@
 /* global Services, Components, dump, LogCapture, LogParser,
    OS, Promise, volumeService, XPCOMUtils, SystemAppProxy */
 
-'use strict';
+"use strict";
 
 const Cu = Components.utils;
 const Ci = Components.interfaces;
 
-Cu.import('resource://gre/modules/XPCOMUtils.jsm');
+Cu.import("resource://gre/modules/XPCOMUtils.jsm");
 
-XPCOMUtils.defineLazyModuleGetter(this, 'LogCapture', 'resource://gre/modules/LogCapture.jsm');
-XPCOMUtils.defineLazyModuleGetter(this, 'LogParser', 'resource://gre/modules/LogParser.jsm');
-XPCOMUtils.defineLazyModuleGetter(this, 'OS', 'resource://gre/modules/osfile.jsm');
-XPCOMUtils.defineLazyModuleGetter(this, 'Promise', 'resource://gre/modules/Promise.jsm');
-XPCOMUtils.defineLazyModuleGetter(this, 'Services', 'resource://gre/modules/Services.jsm');
-XPCOMUtils.defineLazyModuleGetter(this, 'SystemAppProxy', 'resource://gre/modules/SystemAppProxy.jsm');
+XPCOMUtils.defineLazyModuleGetter(this, "LogCapture", "resource://gre/modules/LogCapture.jsm");
+XPCOMUtils.defineLazyModuleGetter(this, "LogParser", "resource://gre/modules/LogParser.jsm");
+XPCOMUtils.defineLazyModuleGetter(this, "OS", "resource://gre/modules/osfile.jsm");
+XPCOMUtils.defineLazyModuleGetter(this, "Promise", "resource://gre/modules/Promise.jsm");
+XPCOMUtils.defineLazyModuleGetter(this, "Services", "resource://gre/modules/Services.jsm");
+XPCOMUtils.defineLazyModuleGetter(this, "SystemAppProxy", "resource://gre/modules/SystemAppProxy.jsm");
 
-XPCOMUtils.defineLazyServiceGetter(this, 'powerManagerService',
-                                   '@mozilla.org/power/powermanagerservice;1',
-                                   'nsIPowerManagerService');
+XPCOMUtils.defineLazyServiceGetter(this, "powerManagerService",
+                                   "@mozilla.org/power/powermanagerservice;1",
+                                   "nsIPowerManagerService");
 
-XPCOMUtils.defineLazyServiceGetter(this, 'volumeService',
-                                   '@mozilla.org/telephony/volume-service;1',
-                                   'nsIVolumeService');
+XPCOMUtils.defineLazyServiceGetter(this, "volumeService",
+                                   "@mozilla.org/telephony/volume-service;1",
+                                   "nsIVolumeService");
 
-this.EXPORTED_SYMBOLS = ['LogShake'];
+this.EXPORTED_SYMBOLS = ["LogShake"];
 
 function debug(msg) {
-  dump('LogShake.jsm: '+msg+'\n');
+  dump("LogShake.jsm: "+msg+"\n");
 }
 
 /**
@@ -54,11 +54,11 @@ function debug(msg) {
  * shake
  */
 const EXCITEMENT_THRESHOLD = 500;
-const DEVICE_MOTION_EVENT = 'devicemotion';
-const SCREEN_CHANGE_EVENT = 'screenchange';
-const CAPTURE_LOGS_START_EVENT = 'capture-logs-start';
-const CAPTURE_LOGS_ERROR_EVENT = 'capture-logs-error';
-const CAPTURE_LOGS_SUCCESS_EVENT = 'capture-logs-success';
+const DEVICE_MOTION_EVENT = "devicemotion";
+const SCREEN_CHANGE_EVENT = "screenchange";
+const CAPTURE_LOGS_START_EVENT = "capture-logs-start";
+const CAPTURE_LOGS_ERROR_EVENT = "capture-logs-error";
+const CAPTURE_LOGS_SUCCESS_EVENT = "capture-logs-success";
 
 let LogShake = {
   QueryInterface: XPCOMUtils.generateQI([Ci.nsIObserver]),
@@ -79,17 +79,18 @@ let LogShake = {
    * Map of files which have log-type information to their parsers
    */
   LOGS_WITH_PARSERS: {
-    '/dev/log/main': LogParser.prettyPrintLogArray,
-    '/dev/log/system': LogParser.prettyPrintLogArray,
-    '/dev/log/radio': LogParser.prettyPrintLogArray,
-    '/dev/log/events': LogParser.prettyPrintLogArray,
-    '/proc/cmdline': LogParser.prettyPrintArray,
-    '/proc/kmsg': LogParser.prettyPrintArray,
-    '/proc/meminfo': LogParser.prettyPrintArray,
-    '/proc/uptime': LogParser.prettyPrintArray,
-    '/proc/version': LogParser.prettyPrintArray,
-    '/proc/vmallocinfo': LogParser.prettyPrintArray,
-    '/proc/vmstat': LogParser.prettyPrintArray
+    "/dev/log/main": LogParser.prettyPrintLogArray,
+    "/dev/log/system": LogParser.prettyPrintLogArray,
+    "/dev/log/radio": LogParser.prettyPrintLogArray,
+    "/dev/log/events": LogParser.prettyPrintLogArray,
+    "/proc/cmdline": LogParser.prettyPrintArray,
+    "/proc/kmsg": LogParser.prettyPrintArray,
+    "/proc/meminfo": LogParser.prettyPrintArray,
+    "/proc/uptime": LogParser.prettyPrintArray,
+    "/proc/version": LogParser.prettyPrintArray,
+    "/proc/vmallocinfo": LogParser.prettyPrintArray,
+    "/proc/vmstat": LogParser.prettyPrintArray,
+    "/system/b2g/application.ini": LogParser.prettyPrintArray
   },
 
   /**
@@ -109,7 +110,7 @@ let LogShake = {
 
     SystemAppProxy.addEventListener(SCREEN_CHANGE_EVENT, this, false);
 
-    Services.obs.addObserver(this, 'xpcom-shutdown', false);
+    Services.obs.addObserver(this, "xpcom-shutdown", false);
   },
 
   /**
@@ -134,7 +135,7 @@ let LogShake = {
    * Handle an observation from Services.obs
    */
   observe: function(subject, topic) {
-    if (topic === 'xpcom-shutdown') {
+    if (topic === "xpcom-shutdown") {
       this.uninit();
     }
   },
@@ -152,8 +153,8 @@ let LogShake = {
   },
 
   /**
-   * Handle a motion event, keeping track of 'excitement', the magnitude
-   * of the device's acceleration.
+   * Handle a motion event, keeping track of "excitement", the magnitude
+   * of the device"s acceleration.
    */
   handleDeviceMotionEvent: function(event) {
     // There is a lag between disabling the event listener and event arrival
@@ -217,11 +218,25 @@ let LogShake = {
       Cu.reportError("Unable to get device properties: " + ex);
     }
 
+    // Let Gecko perfom the dump to a file, and just collect it
+    try {
+      LogCapture.readAboutMemory().then(aboutMemory => {
+        let file = OS.Path.basename(aboutMemory);
+        logArrays[file] =
+          LogParser.prettyPrintArray(LogCapture.readLogFile(aboutMemory));
+        // We need to remove the dumped file, now that we have it in memory
+        OS.File.remove(aboutMemory);
+      });
+    } catch (ex) {
+      Cu.reportError("Unable to get about:memory dump: " + ex);
+    }
+
     for (let loc in this.LOGS_WITH_PARSERS) {
       let logArray;
       try {
         logArray = LogCapture.readLogFile(loc);
         if (!logArray) {
+          debug("LogCapture.readLogFile() returned nothing for: " + loc);
           continue;
         }
       } catch (ex) {
@@ -245,32 +260,40 @@ let LogShake = {
   uninit: function() {
     this.stopDeviceMotionListener();
     SystemAppProxy.removeEventListener(SCREEN_CHANGE_EVENT, this, false);
-    Services.obs.removeObserver(this, 'xpcom-shutdown');
+    Services.obs.removeObserver(this, "xpcom-shutdown");
   }
 };
 
 function getLogFilename(logLocation) {
   // sanitize the log location
-  let logName = logLocation.replace(/\//g, '-');
-  if (logName[0] === '-') {
+  let logName = logLocation.replace(/\//g, "-");
+  if (logName[0] === "-") {
     logName = logName.substring(1);
   }
-  return logName + '.log';
+
+  // If no extension is provided, default to forcing .log
+  let extension = ".log";
+  let logLocationExt = logLocation.split(".");
+  if (logLocationExt.length > 1) {
+    // otherwise, just append nothing
+    extension = "";
+  }
+
+  return logName + extension;
 }
 
 function getSdcardPrefix() {
-  return volumeService.getVolumeByName('sdcard').mountPoint;
+  return volumeService.getVolumeByName("sdcard").mountPoint;
 }
 
 function getLogDirectoryRoot() {
-  return 'logs';
+  return "logs";
 }
 
 function getLogDirectory() {
   let d = new Date();
   d = new Date(d.getTime() - d.getTimezoneOffset() * 60000);
-  let timestamp = d.toISOString().slice(0, -5).replace(/[:T]/g, '-');
-  // return directory name of format 'logs/timestamp/'
+  let timestamp = d.toISOString().slice(0, -5).replace(/[:T]/g, "-");
   return timestamp;
 }
 
@@ -281,7 +304,7 @@ function saveLogs(logArrays) {
   if (!logArrays || Object.keys(logArrays).length === 0) {
     return Promise.resolve({
       logFilenames: [],
-      logPrefix: ''
+      logPrefix: ""
     });
   }
 
@@ -296,7 +319,7 @@ function saveLogs(logArrays) {
     return Promise.reject(e);
   }
 
-  debug('making a directory all the way from '+sdcardPrefix+' to '+(sdcardPrefix + '/' + dirNameRoot + '/' + dirName));
+  debug("making a directory all the way from " + sdcardPrefix + " to " + (sdcardPrefix + "/" + dirNameRoot + "/" + dirName) );
   let logsRoot = OS.Path.join(sdcardPrefix, dirNameRoot);
   return OS.File.makeDir(logsRoot, {from: sdcardPrefix}).then(
     function() {
@@ -308,7 +331,7 @@ function saveLogs(logArrays) {
           let saveRequests = [];
 
           for (let logLocation in logArrays) {
-            debug('requesting save of ' + logLocation);
+            debug("requesting save of " + logLocation);
             let logArray = logArrays[logLocation];
             // The filename represents the relative path within the SD card, not the
             // absolute path because Gaia will refer to it using the DeviceStorage
@@ -321,7 +344,7 @@ function saveLogs(logArrays) {
 
           return Promise.all(saveRequests).then(
             function() {
-              debug('returning logfilenames: '+logFilenames.toSource());
+              debug("returning logfilenames: "+logFilenames.toSource());
               return {
                 logFilenames: logFilenames,
                 logPrefix: OS.Path.join(dirNameRoot, dirName)

b2g/components/test/unit/test_logcapture.js

@@ -1,30 +1,13 @@
-/* Any copyright is dedicated to the Public Domain.
-   http://creativecommons.org/publicdomain/zero/1.0/ */
-
-
 /**
- * Test that LogCapture successfully reads from the /dev/log devices, returning
- * a Uint8Array of some length, including zero. This tests a few standard
- * log devices
+ * Testing non Gonk-specific code path
  */
 function run_test() {
   Components.utils.import("resource:///modules/LogCapture.jsm");
-
-  function verifyLog(log) {
-    // log exists
-    notEqual(log, null);
-    // log has a length and it is non-negative (is probably array-like)
-    ok(log.length >= 0);
-  }
-
-  let propertiesLog = LogCapture.readProperties();
-  notEqual(propertiesLog, null, "Properties should not be null");
-  notEqual(propertiesLog, undefined, "Properties should not be undefined");
-  equal(propertiesLog["ro.kernel.qemu"], "1", "QEMU property should be 1");
-
-  let mainLog = LogCapture.readLogFile("/dev/log/main");
-  verifyLog(mainLog);
-
-  let meminfoLog = LogCapture.readLogFile("/proc/meminfo");
-  verifyLog(meminfoLog);
+  run_next_test();
 }
+
+// Trivial test just to make sure we have no syntax error
+add_test(function test_logCapture_loads() {
+  ok(LogCapture, "LogCapture object exists");
+  run_next_test();
+});

b2g/components/test/unit/test_logcapture_gonk.js

@@ -0,0 +1,61 @@
+/* Any copyright is dedicated to the Public Domain.
+   http://creativecommons.org/publicdomain/zero/1.0/ */
+
+
+/**
+ * Test that LogCapture successfully reads from the /dev/log devices, returning
+ * a Uint8Array of some length, including zero. This tests a few standard
+ * log devices
+ */
+function run_test() {
+  Components.utils.import("resource:///modules/LogCapture.jsm");
+  run_next_test();
+}
+
+function verifyLog(log) {
+  // log exists
+  notEqual(log, null);
+  // log has a length and it is non-negative (is probably array-like)
+  ok(log.length >= 0);
+}
+
+add_test(function test_readLogFile() {
+  let mainLog = LogCapture.readLogFile("/dev/log/main");
+  verifyLog(mainLog);
+
+  let meminfoLog = LogCapture.readLogFile("/proc/meminfo");
+  verifyLog(meminfoLog);
+
+  run_next_test();
+});
+
+add_test(function test_readProperties() {
+  let propertiesLog = LogCapture.readProperties();
+  notEqual(propertiesLog, null, "Properties should not be null");
+  notEqual(propertiesLog, undefined, "Properties should not be undefined");
+  equal(propertiesLog["ro.kernel.qemu"], "1", "QEMU property should be 1");
+
+  run_next_test();
+});
+
+add_test(function test_readAppIni() {
+  let appIni = LogCapture.readLogFile("/system/b2g/application.ini");
+  verifyLog(appIni);
+
+  run_next_test();
+});
+
+
+add_test(function test_get_about_memory() {
+  let memLog = LogCapture.readAboutMemory();
+
+  ok(memLog, "Should have returned a valid Promise object");
+
+  memLog.then(file => {
+    ok(file, "Should have returned a filename");
+    run_next_test();
+  }, error => {
+    ok(false, "Dumping about:memory promise rejected: " + error);
+    run_next_test();
+  });
+});

b2g/components/test/unit/test_logshake_gonk.js

@@ -0,0 +1,121 @@
+/**
+ * Test the log capturing capabilities of LogShake.jsm, checking
+ * for Gonk-specific parts
+ */
+
+/* jshint moz: true */
+/* global Components, LogCapture, LogShake, ok, add_test, run_next_test, dump */
+/* exported run_test */
+
+/* disable use strict warning */
+/* jshint -W097 */
+
+"use strict";
+
+const Cu = Components.utils;
+const Ci = Components.interfaces;
+const Cc = Components.classes;
+
+Cu.import("resource://gre/modules/XPCOMUtils.jsm");
+
+XPCOMUtils.defineLazyServiceGetter(this, "volumeService",
+                                   "@mozilla.org/telephony/volume-service;1",
+                                   "nsIVolumeService");
+
+let sdcard;
+
+function run_test() {
+  Cu.import("resource://gre/modules/LogShake.jsm");
+  Cu.import("resource://gre/modules/Promise.jsm");
+  Cu.import("resource://gre/modules/osfile.jsm");
+  do_get_profile();
+  debug("Starting");
+  run_next_test();
+}
+
+function debug(msg) {
+  var timestamp = Date.now();
+  dump("LogShake: " + timestamp + ": " + msg + "\n");
+}
+
+add_test(function setup_fs() {
+  OS.File.makeDir("/data/local/tmp/sdcard/", {from: "/data"}).then(function() {
+    run_next_test();
+  });
+});
+
+add_test(function setup_sdcard() {
+  let volName = "sdcard";
+  let mountPoint = "/data/local/tmp/sdcard";
+  volumeService.createFakeVolume(volName, mountPoint);
+
+  let vol = volumeService.getVolumeByName(volName);
+  ok(vol, "volume shouldn't be null");
+  equal(volName, vol.name, "name");
+
+  volumeService.SetFakeVolumeState(volName, Ci.nsIVolume.STATE_MOUNTED);
+  equal(Ci.nsIVolume.STATE_MOUNTED, vol.state, "state");
+
+  run_next_test();
+});
+
+add_test(function test_ensure_sdcard() {
+  sdcard = volumeService.getVolumeByName("sdcard").mountPoint;
+  ok(sdcard, "Should have a valid sdcard mountpoint");
+  run_next_test();
+});
+
+add_test(function test_logShake_captureLogs_returns() {
+  // Enable LogShake
+  LogShake.init();
+
+  LogShake.captureLogs().then(logResults => {
+    LogShake.uninit();
+
+    ok(logResults.logFilenames.length > 0, "Should have filenames");
+    ok(logResults.logPrefix.length > 0, "Should have prefix");
+
+    run_next_test();
+  },
+  error => {
+    LogShake.uninit();
+
+    ok(false, "Should not have received error: " + error);
+
+    run_next_test();
+  });
+});
+
+add_test(function test_logShake_captureLogs_writes() {
+  // Enable LogShake
+  LogShake.init();
+
+  let expectedFiles = [];
+
+  LogShake.captureLogs().then(logResults => {
+    LogShake.uninit();
+
+    logResults.logFilenames.forEach(f => {
+      let p = OS.Path.join(sdcard, f);
+      ok(p, "Should have a valid result path: " + p);
+
+      let t = OS.File.exists(p).then(rv => {
+        ok(rv, "File exists: " + p);
+      });
+
+      expectedFiles.push(t);
+    });
+
+    Promise.all(expectedFiles).then(() => {
+      ok(true, "Completed all files checks");
+      run_next_test();
+    });
+  },
+  error => {
+    LogShake.uninit();
+
+    ok(false, "Should not have received error: " + error);
+
+    run_next_test();
+  });
+});

b2g/components/test/unit/xpcshell.ini

@@ -14,10 +14,17 @@ support-files =
 head = head_identity.js
 tail =
 
+# testing non gonk-specific stuff
 [test_logcapture.js]
+
+[test_logcapture_gonk.js]
 # only run on b2g builds due to requiring b2g-specific log files to exist
 skip-if = toolkit != "gonk"
 
 [test_logparser.js]
 
 [test_logshake.js]
+
+[test_logshake_gonk.js]
+# only run on b2g builds due to requiring b2g-specific log files to exist
+skip-if = toolkit != "gonk"