Bug 1079763 - Compress logs produced by LogShake. r=gerard-majax

b2g/chrome/content/settings.js

@@ -213,13 +213,21 @@ let LogShake;
   LogShake.init();
 })();
 
-SettingsListener.observe('devtools.logshake', false, value => {
+SettingsListener.observe('devtools.logshake.enabled', false, value => {
   if (value) {
     LogShake.enableDeviceMotionListener();
   } else {
     LogShake.disableDeviceMotionListener();
   }
 });
+
+SettingsListener.observe('devtools.logshake.qa_enabled', false, value => {
+  if (value) {
+    LogShake.enableQAMode();
+  } else {
+    LogShake.disableQAMode();
+  }
+});
 #endif
 
 // =================== Device Storage ====================

b2g/components/LogParser.jsm

@@ -203,33 +203,43 @@ function formatLogMessage(logMessage) {
          ": " + logMessage.message;
 }
 
+/**
+ * Convert a string to a utf-8 Uint8Array
+ * @param {String} str
+ * @return {Uint8Array}
+ */
+function textEncode(str) {
+  return new TextEncoder("utf-8").encode(str);
+}
+
 /**
  * Pretty-print an array of bytes read from a log file by parsing then
  * threadtime formatting its entries.
  * @param array {Uint8Array} Array of a log file's bytes
- * @return {String} Pretty-printed log
+ * @return {Uint8Array} Pretty-printed log
  */
 function prettyPrintLogArray(array) {
   let logMessages = parseLogArray(array);
-  return logMessages.map(formatLogMessage).join("");
+  return textEncode(logMessages.map(formatLogMessage).join(""));
 }
 
 /**
  * Pretty-print an array read from the list of propreties.
  * @param {Object} Object representing the properties
- * @return {String} Human-readable string of property name: property value
+ * @return {Uint8Array} Human-readable string of property name: property value
  */
 function prettyPrintPropertiesArray(properties) {
   let propertiesString = "";
   for(let propName in properties) {
     propertiesString += "[" + propName + "]: [" + properties[propName] + "]\n";
   }
-  return propertiesString;
+  return textEncode(propertiesString);
 }
 
 /**
  * Pretty-print a normal array. Does nothing.
  * @param array {Uint8Array} Input array
+ * @return {Uint8Array} The same array
  */
 function prettyPrintArray(array) {
   return array;

b2g/components/LogShake.jsm

@@ -7,15 +7,16 @@
  * response to a sufficiently large acceleration (a shake), it will save log
  * files to an arbitrary directory which it will then return on a
  * 'capture-logs-success' event with detail.logFilenames representing each log
- * file's filename in the directory. If an error occurs it will instead produce
- * a 'capture-logs-error' event.
+ * file's name and detail.logPaths representing the patch to each log file or
+ * the path to the archive.
+ * If an error occurs it will instead produce a 'capture-logs-error' event.
  * We send a capture-logs-start events to notify the system app and the user,
  * since dumping can be a bit long sometimes.
  */
 
 /* enable Mozilla javascript extensions and global strictness declaration,
  * disable valid this checking */
-/* jshint moz: true */
+/* jshint moz: true, esnext: true */
 /* jshint -W097 */
 /* jshint -W040 */
 /* global Services, Components, dump, LogCapture, LogParser,
@@ -23,11 +24,17 @@
 
 "use strict";
 
-const Cu = Components.utils;
+const Cc = Components.classes;
 const Ci = Components.interfaces;
+const Cu = Components.utils;
 
 Cu.import("resource://gre/modules/XPCOMUtils.jsm");
 
+// Constants for creating zip file taken from toolkit/webapps/tests/head.js
+const PR_RDWR        = 0x04;
+const PR_CREATE_FILE = 0x08;
+const PR_TRUNCATE    = 0x20;
+
 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");
@@ -69,6 +76,12 @@ const CAPTURE_LOGS_SUCCESS_EVENT = "capture-logs-success";
 
 let LogShake = {
   QueryInterface: XPCOMUtils.generateQI([Ci.nsIObserver]),
+
+  /**
+   * If LogShake is in QA Mode, which bundles all files into a compressed archive
+   */
+  qaModeEnabled: false,
+
   /**
    * If LogShake is listening for device motion events. Required due to lag
    * between HAL layer of device motion events and listening for device motion
@@ -173,6 +186,16 @@ let LogShake = {
     }
   },
 
+  enableQAMode: function() {
+    debug("Enabling QA Mode");
+    this.qaModeEnabled = true;
+  },
+
+  disableQAMode: function() {
+    debug("Disabling QA Mode");
+    this.qaModeEnabled = false;
+  },
+
   enableDeviceMotionListener: function() {
     this.listenToDeviceMotion = true;
     this.startDeviceMotionListener();
@@ -208,11 +231,11 @@ let LogShake = {
       return;
     }
 
-    var acc = event.accelerationIncludingGravity;
+    let acc = event.accelerationIncludingGravity;
 
     // Updates excitement by a factor of at most alpha, ignoring sudden device
     // motion. See bug #1101994 for more information.
-    var newExcitement = acc.x * acc.x + acc.y * acc.y + acc.z * acc.z;
+    let newExcitement = acc.x * acc.x + acc.y * acc.y + acc.z * acc.z;
     this.excitement += (newExcitement - this.excitement) * EXCITEMENT_FILTER_ALPHA;
 
     if (this.excitement > EXCITEMENT_THRESHOLD) {
@@ -229,8 +252,8 @@ let LogShake = {
     this.captureLogs().then(logResults => {
       // On resolution send the success event to the requester
       SystemAppProxy._sendCustomEvent(CAPTURE_LOGS_SUCCESS_EVENT, {
-        logFilenames: logResults.logFilenames,
-        logPrefix: logResults.logPrefix
+        logPaths: logResults.logPaths,
+        logFilenames: logResults.logFilenames
       });
       this.captureRequested = false;
     }, error => {
@@ -255,7 +278,7 @@ let LogShake = {
    */
   captureLogs: function() {
     let logArrays = this.readLogs();
-    return saveLogs(logArrays);
+    return this.saveLogs(logArrays);
   },
 
   /**
@@ -323,6 +346,25 @@ let LogShake = {
     return logArrays;
   },
 
+  /**
+   * Save the formatted arrays of log files to an sdcard if available
+   */
+  saveLogs: function(logArrays) {
+    if (!logArrays || Object.keys(logArrays).length === 0) {
+      return Promise.reject("Zero logs saved");
+    }
+
+    if (this.qaModeEnabled) {
+      return makeBaseLogsDirectory().then(writeLogArchive(logArrays),
+                                          rejectFunction("Error making base log directory"));
+    } else {
+      return makeBaseLogsDirectory().then(makeLogsDirectory,
+                                          rejectFunction("Error making base log directory"))
+                                    .then(writeLogFiles(logArrays),
+                                          rejectFunction("Error creating log directory"));
+    }
+  },
+
   /**
    * Stop logshake, removing all listeners
    */
@@ -359,82 +401,168 @@ function getLogDirectoryRoot() {
   return "logs";
 }
 
-function getLogDirectory() {
+function getLogIdentifier() {
   let d = new Date();
   d = new Date(d.getTime() - d.getTimezoneOffset() * 60000);
   let timestamp = d.toISOString().slice(0, -5).replace(/[:T]/g, "-");
   return timestamp;
 }
 
-/**
- * Save the formatted arrays of log files to an sdcard if available
- */
-function saveLogs(logArrays) {
-  if (!logArrays || Object.keys(logArrays).length === 0) {
-    return Promise.resolve({
-      logFilenames: [],
-      logPrefix: ""
-    });
-  }
+function rejectFunction(message) {
+  return function(err) {
+    debug(message + ": " + err);
+    return Promise.reject(err);
+  };
+}
 
-  let sdcardPrefix, dirNameRoot, dirName;
+function makeBaseLogsDirectory() {
+  let sdcardPrefix;
   try {
     sdcardPrefix = getSdcardPrefix();
-    dirNameRoot = getLogDirectoryRoot();
-    dirName = getLogDirectory();
   } catch(e) {
-    // Return promise failed with exception e
     // Handles missing sdcard
     return Promise.reject(e);
   }
 
-  debug("making a directory all the way from " + sdcardPrefix + " to " + (sdcardPrefix + "/" + dirNameRoot + "/" + dirName) );
+  let dirNameRoot = getLogDirectoryRoot();
+
   let logsRoot = OS.Path.join(sdcardPrefix, dirNameRoot);
+
+  debug("Creating base log directory at root " + sdcardPrefix);
+
   return OS.File.makeDir(logsRoot, {from: sdcardPrefix}).then(
     function() {
-      debug("First OS.File.makeDir done");
-      let logsDir = OS.Path.join(logsRoot, dirName);
-      debug("Creating " + logsDir);
-      return OS.File.makeDir(logsDir, {ignoreExisting: false}).then(
-        function() {
-          debug("Created: " + logsDir);
-          // Now the directory is guaranteed to exist, save the logs
-          let logFilenames = [];
-          let saveRequests = [];
+      return {
+        sdcardPrefix: sdcardPrefix,
+        basePrefix: dirNameRoot
+      };
+    }
+  );
+}
 
-          debug("Will now traverse logArrays: " + logArrays.length);
+function makeLogsDirectory({sdcardPrefix, basePrefix}) {
+  let dirName = getLogIdentifier();
 
-          for (let logLocation in logArrays) {
-            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
-            // API
-            let filename = OS.Path.join(dirNameRoot, dirName, getLogFilename(logLocation));
-            logFilenames.push(filename);
-            let saveRequest = OS.File.writeAtomic(OS.Path.join(sdcardPrefix, filename), logArray);
-            saveRequests.push(saveRequest);
-          }
+  let logsRoot = OS.Path.join(sdcardPrefix, basePrefix);
+  let logsDir = OS.Path.join(logsRoot, dirName);
 
-          return Promise.all(saveRequests).then(
-            function() {
-              debug("returning logfilenames: "+logFilenames.toSource());
-              return {
-                logFilenames: logFilenames,
-                logPrefix: OS.Path.join(dirNameRoot, dirName)
-              };
-            }, function(err) {
-              debug("Error at some save request: " + err);
-              return Promise.reject(err);
-            });
-        }, function(err) {
-          debug("Error at OS.File.makeDir for " + logsDir + ": " + err);
-          return Promise.reject(err);
-        });
-    }, function(err) {
-      debug("Error at first OS.File.makeDir: " + err);
-      return Promise.reject(err);
-    });
+  debug("Creating base log directory at root " + sdcardPrefix);
+  debug("Final created directory will be " + logsDir);
+
+  return OS.File.makeDir(logsDir, {ignoreExisting: false}).then(
+    function() {
+      debug("Created: " + logsDir);
+      return {
+        logPrefix: OS.Path.join(basePrefix, dirName),
+        sdcardPrefix: sdcardPrefix
+      };
+    },
+    rejectFunction("Error at OS.File.makeDir for " + logsDir)
+  );
+}
+
+function getFile(filename) {
+  let file = Cc["@mozilla.org/file/local;1"].createInstance(Ci.nsIFile);
+  file.initWithPath(filename);
+  return file;
+}
+
+/**
+ * Make a zip file
+ * @param {String} absoluteZipFilename - Fully qualified desired location of the zip file
+ * @param {Map<String, Uint8Array>} logArrays - Map from log location to log data
+ * @return {Array<String>} Paths of entries in the archive
+ */
+function makeZipFile(absoluteZipFilename, logArrays) {
+  let logFilenames = [];
+  let zipWriter = Cc["@mozilla.org/zipwriter;1"].createInstance(Ci.nsIZipWriter);
+  let zipFile = getFile(absoluteZipFilename);
+  zipWriter.open(zipFile, PR_RDWR | PR_CREATE_FILE | PR_TRUNCATE);
+
+  for (let logLocation in logArrays) {
+    let logArray = logArrays[logLocation];
+    let logFilename = getLogFilename(logLocation);
+    logFilenames.push(logFilename);
+
+    debug("Adding " + logFilename + " to the zip");
+    let logArrayStream = Cc["@mozilla.org/io/arraybuffer-input-stream;1"]
+                           .createInstance(Ci.nsIArrayBufferInputStream);
+    // Set data to be copied, default offset to 0 because it is not present on
+    // ArrayBuffer objects
+    logArrayStream.setData(logArray.buffer, logArray.byteOffset || 0,
+                           logArray.byteLength);
+
+    zipWriter.addEntryStream(logFilename, Date.now(),
+                             Ci.nsIZipWriter.COMPRESSION_DEFAULT,
+                             logArrayStream, false);
+  }
+  zipWriter.close();
+
+  return logFilenames;
+}
+
+function writeLogArchive(logArrays) {
+  return function({sdcardPrefix, basePrefix}) {
+    // Now the directory is guaranteed to exist, save the logs into their
+    // archive file
+
+    let zipFilename = getLogIdentifier() + "-logs.zip";
+    let zipPath = OS.Path.join(basePrefix, zipFilename);
+    let zipPrefix = OS.Path.dirname(zipPath);
+    let absoluteZipPath = OS.Path.join(sdcardPrefix, zipPath);
+
+    debug("Creating zip file at " + zipPath);
+    let logFilenames = [];
+    try {
+      logFilenames = makeZipFile(absoluteZipPath, logArrays);
+    } catch(e) {
+      return Promise.reject(e);
+    }
+    debug("Zip file created");
+
+    return {
+      logFilenames: logFilenames,
+      logPaths: [zipPath],
+      compressed: true
+    };
+  };
+}
+
+function writeLogFiles(logArrays) {
+  return function({sdcardPrefix, logPrefix}) {
+    // Now the directory is guaranteed to exist, save the logs
+    let logFilenames = [];
+    let logPaths = [];
+    let saveRequests = [];
+
+    for (let logLocation in logArrays) {
+      debug("Requesting save of " + logLocation);
+      let logArray = logArrays[logLocation];
+      let logFilename = getLogFilename(logLocation);
+      // The local pathrepresents the relative path within the SD card, not the
+      // absolute path because Gaia will refer to it using the DeviceStorage
+      // API
+      let localPath = OS.Path.join(logPrefix, logFilename);
+
+      logFilenames.push(logFilename);
+      logPaths.push(localPath);
+
+      let absolutePath = OS.Path.join(sdcardPrefix, localPath);
+      let saveRequest = OS.File.writeAtomic(absolutePath, logArray);
+      saveRequests.push(saveRequest);
+    }
+
+    return Promise.all(saveRequests).then(
+      function() {
+        return {
+          logFilenames: logFilenames,
+          logPaths: logPaths,
+          compressed: false
+        };
+      },
+      rejectFunction("Error at some save request")
+    );
+  };
 }
 
 LogShake.init();

b2g/components/test/unit/test_logparser.js

@@ -54,7 +54,8 @@ add_test(function test_print_properties() {
     "sys.usb.state": "diag,serial_smd,serial_tty,rmnet_bam,mass_storage,adb"
   };
 
-  let logMessages = LogParser.prettyPrintPropertiesArray(properties);
+  let logMessagesRaw = LogParser.prettyPrintPropertiesArray(properties);
+  let logMessages = new TextDecoder("utf-8").decode(logMessagesRaw);
   let logMessagesArray = logMessages.split("\n");
 
   ok(logMessagesArray.length === 3, "There should be 3 lines in the log.");

b2g/components/test/unit/test_logshake_gonk.js

@@ -73,9 +73,10 @@ add_test(function test_logShake_captureLogs_writes() {
     LogShake.uninit();
 
     ok(logResults.logFilenames.length > 0, "Should have filenames");
-    ok(logResults.logPrefix.length > 0, "Should have prefix");
+    ok(logResults.logPaths.length > 0, "Should have paths");
+    ok(!logResults.compressed, "Should not be compressed");
 
-    logResults.logFilenames.forEach(f => {
+    logResults.logPaths.forEach(f => {
       let p = OS.Path.join(sdcard, f);
       ok(p, "Should have a valid result path: " + p);
 

b2g/components/test/unit/test_logshake_gonk_compression.js

@@ -0,0 +1,117 @@
+/**
+ * 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");
+  Cu.import("resource://gre/modules/FileUtils.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");
+  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_writes_zip() {
+  // Enable LogShake
+  LogShake.init();
+
+  let expectedFiles = [];
+
+  LogShake.enableQAMode();
+
+  LogShake.captureLogs().then(logResults => {
+    LogShake.uninit();
+
+    ok(logResults.logPaths.length === 1, "Should have zip path");
+    ok(logResults.logFilenames.length >= 1, "Should have log filenames");
+    ok(logResults.compressed, "Log files should be compressed");
+
+    let zipPath = OS.Path.join(sdcard, logResults.logPaths[0]);
+    ok(zipPath, "Should have a valid archive path: " + zipPath);
+
+    let zipFile = new FileUtils.File(zipPath);
+    ok(zipFile, "Should have a valid archive file: " + zipFile);
+
+    let zipReader = Cc["@mozilla.org/libjar/zip-reader;1"]
+                      .createInstance(Ci.nsIZipReader);
+    zipReader.open(zipFile);
+
+    let logFilenamesSeen = {};
+
+    let zipEntries = zipReader.findEntries(null); // Find all entries
+    while (zipEntries.hasMore()) {
+      let entryName = zipEntries.getNext();
+      let entry = zipReader.getEntry(entryName);
+      logFilenamesSeen[entryName] = true;
+      ok(!entry.isDirectory, "Archive entry " + entryName + " should be a file");
+    }
+    zipReader.close();
+
+    // TODO: Verify archive contents
+    logResults.logFilenames.forEach(filename => {
+      ok(logFilenamesSeen[filename], "File " + filename + " should be present in archive");
+    });
+    run_next_test();
+  },
+  error => {
+    LogShake.uninit();
+
+    ok(false, "Should not have received error: " + error);
+
+    run_next_test();
+  });
+});
+

b2g/components/test/unit/xpcshell.ini

@@ -29,4 +29,8 @@ skip-if = toolkit != "gonk"
 # only run on b2g builds due to requiring b2g-specific log files to exist
 skip-if = (toolkit != "gonk")
 
+[test_logshake_gonk_compression.js]
+# only run on b2g builds due to requiring b2g-specific log files to exist
+skip-if = (toolkit != "gonk")
+
 [test_aboutserviceworkers.js]