Bug 1079322 - Extract properties using libc functions. r=gwagner

The LogShake features allows one to shake its device to be able to dump
a set of useful logging informations. This includes several log files,
and also the Android properties. In the past, we relied on the
/dev/__properties__ file to extract their content by parsing its value.
This is duplicate work from the bionic libc and libcutils library.
Worst, the format used to store the values in this file has been changed
between JellyBean and Kitkat, so our parser was not able to dump the
values: that explains bug 1079322. To fix this we make use of some of
the underlying libc-defined functions used to iterate and get properties
values:
 - __system_property_find_nth() to retrieve one arbitrary property by
   its number (starting from 0), and this returns a struct containing
   all the informations
 - __system_property_read() to read the values contained in the struct
   that was previously retrieved

b2g/components/LogCapture.jsm

@@ -8,22 +8,27 @@
 
 this.EXPORTED_SYMBOLS = ['LogCapture'];
 
-/**
- * readLogFile
- * Read in /dev/log/{{log}} in nonblocking mode, which will return -1 if
- * reading would block the thread.
- *
- * @param log {String} The log from which to read. Must be present in /dev/log
- * @return {Uint8Array} Raw log data
- */
-let readLogFile = function(logLocation) {
-  if (!this.ctypes) {
+const SYSTEM_PROPERTY_KEY_MAX = 32;
+const SYSTEM_PROPERTY_VALUE_MAX = 92;
+
+function debug(msg) {
+  dump('LogCapture.jsm: ' + msg + '\n');
+}
+
+let LogCapture = {
+  ensureLoaded: function() {
+    if (!this.ctypes) {
+      this.load();
+    }
+  },
+
+  load: function() {
     // load in everything on first use
     Components.utils.import('resource://gre/modules/ctypes.jsm', this);
 
-    this.lib = this.ctypes.open(this.ctypes.libraryName('c'));
+    this.libc = this.ctypes.open(this.ctypes.libraryName('c'));
 
-    this.read = this.lib.declare('read',
+    this.read = this.libc.declare('read',
       this.ctypes.default_abi,
       this.ctypes.int,       // bytes read (out)
       this.ctypes.int,       // file descriptor (in)
@@ -31,61 +36,124 @@ let readLogFile = function(logLocation) {
       this.ctypes.size_t     // size_t size of buffer (in)
     );
 
-    this.open = this.lib.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.lib.declare('close',
+    this.close = this.libc.declare('close',
       this.ctypes.default_abi,
       this.ctypes.int, // error code (returned)
       this.ctypes.int  // file descriptor
     );
-  }
 
-  const O_READONLY = 0;
-  const O_NONBLOCK = 1 << 11;
+    this.property_find_nth =
+      this.libc.declare("__system_property_find_nth",
+                        this.ctypes.default_abi,
+                        this.ctypes.voidptr_t,     // return value: nullable prop_info*
+                        this.ctypes.unsigned_int); // n: the index of the property to return
 
-  const BUF_SIZE = 2048;
+    this.property_read =
+      this.libc.declare("__system_property_read",
+                        this.ctypes.default_abi,
+                        this.ctypes.void_t,     // return: none
+                        this.ctypes.voidptr_t,  // non-null prop_info*
+                        this.ctypes.char.ptr,   // key
+                        this.ctypes.char.ptr);  // value
 
-  let BufType = this.ctypes.ArrayType(this.ctypes.char);
-  let buf = new BufType(BUF_SIZE);
-  let logArray = [];
+    this.key_buf   = this.ctypes.char.array(SYSTEM_PROPERTY_KEY_MAX)();
+    this.value_buf = this.ctypes.char.array(SYSTEM_PROPERTY_VALUE_MAX)();
+  },
 
-  let logFd = this.open(logLocation, O_READONLY | O_NONBLOCK);
-  if (logFd === -1) {
-    return null;
-  }
+  cleanup: function() {
+    this.libc.close();
 
-  let readStart = Date.now();
-  let readCount = 0;
-  while (true) {
-    let count = this.read(logFd, buf, BUF_SIZE);
-    readCount += 1;
+    this.read = null;
+    this.open = null;
+    this.close = null;
+    this.property_find_nth = null;
+    this.property_read = null;
+    this.key_buf = null;
+    this.value_buf = null;
 
-    if (count <= 0) {
-      // log has return due to being nonblocking or running out of things
-      break;
+    this.libc = null;
+    this.ctypes = null;
+  },
+
+  /**
+   * readLogFile
+   * Read in /dev/log/{{log}} in nonblocking mode, which will return -1 if
+   * reading would block the thread.
+   *
+   * @param log {String} The log from which to read. Must be present in /dev/log
+   * @return {Uint8Array} Raw log data
+   */
+  readLogFile: function(logLocation) {
+    this.ensureLoaded();
+
+    const O_READONLY = 0;
+    const O_NONBLOCK = 1 << 11;
+
+    const BUF_SIZE = 2048;
+
+    let BufType = this.ctypes.ArrayType(this.ctypes.char);
+    let buf = new BufType(BUF_SIZE);
+    let logArray = [];
+
+    let logFd = this.open(logLocation, O_READONLY | O_NONBLOCK);
+    if (logFd === -1) {
+      return null;
     }
-    for(let i = 0; i < count; i++) {
-      logArray.push(buf[i]);
+
+    let readStart = Date.now();
+    let readCount = 0;
+    while (true) {
+      let count = this.read(logFd, buf, BUF_SIZE);
+      readCount += 1;
+
+      if (count <= 0) {
+        // log has return due to being nonblocking or running out of things
+        break;
+      }
+      for(let i = 0; i < count; i++) {
+        logArray.push(buf[i]);
+      }
     }
+
+    let logTypedArray = new Uint8Array(logArray);
+
+    this.close(logFd);
+
+    return logTypedArray;
+  },
+
+ /**
+   * Get all system properties as a dict with keys mapping to values
+   */
+  readProperties: function() {
+    this.ensureLoaded();
+    let n = 0;
+    let propertyDict = {};
+
+    while(true) {
+      let prop_info = this.property_find_nth(n);
+      if(prop_info.isNull()) {
+        break;
+      }
+
+      // read the prop_info into the key and value buffers
+      this.property_read(prop_info, this.key_buf, this.value_buf);
+      let key = this.key_buf.readString();;
+      let value = this.value_buf.readString()
+
+      propertyDict[key] = value;
+      n++;
+    }
+
+    return propertyDict;
   }
-
-  let logTypedArray = new Uint8Array(logArray);
-
-  this.close(logFd);
-
-  return logTypedArray;
 };
 
-let cleanup = function() {
-  this.lib.close();
-  this.read = this.open = this.close = null;
-  this.lib = null;
-  this.ctypes = null;
-};
-
-this.LogCapture = { readLogFile: readLogFile, cleanup: cleanup };
+this.LogCapture = LogCapture;

b2g/components/LogParser.jsm

@@ -215,71 +215,14 @@ function prettyPrintLogArray(array) {
 }
 
 /**
- * Parse an array of bytes as a properties file. The structure of the
- * properties file is derived from bionic/libc/bionic/system_properties.c
- * @param array {Uint8Array} Array containing property data
- * @return {Object} Map from property name to property value, both strings
- */
-function parsePropertiesArray(array) {
-  let data = new DataView(array.buffer);
-  let byteString = String.fromCharCode.apply(null, array);
-
-  let properties = {};
-
-  let propIndex = 0;
-  let propCount = data.getUint32(0, true);
-
-  // first TOC entry is at 32
-  let tocOffset = 32;
-
-  const PROP_NAME_MAX = 32;
-  const PROP_VALUE_MAX = 92;
-
-  while (propIndex < propCount) {
-    // Retrieve offset from file start
-    let infoOffset = data.getUint32(tocOffset, true) & 0xffffff;
-
-    // Now read the name, integer serial, and value
-    let propName = "";
-    let nameOffset = infoOffset;
-    while (byteString[nameOffset] != "\0" &&
-           (nameOffset - infoOffset) < PROP_NAME_MAX) {
-      propName += byteString[nameOffset];
-      nameOffset ++;
-    }
-
-    infoOffset += PROP_NAME_MAX;
-    // Skip serial number
-    infoOffset += 4;
-
-    let propValue = "";
-    nameOffset = infoOffset;
-    while (byteString[nameOffset] != "\0" &&
-           (nameOffset - infoOffset) < PROP_VALUE_MAX) {
-      propValue += byteString[nameOffset];
-      nameOffset ++;
-    }
-
-    // Move to next table of contents entry
-    tocOffset += 4;
-
-    properties[propName] = propValue;
-    propIndex += 1;
-  }
-
-  return properties;
-}
-
-/**
- * Pretty-print an array read from the /dev/__properties__ file.
- * @param array {Uint8Array} File data array
+ * 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
  */
-function prettyPrintPropertiesArray(array) {
-  let properties = parsePropertiesArray(array);
+function prettyPrintPropertiesArray(properties) {
   let propertiesString = "";
   for(let propName in properties) {
-    propertiesString += propName + ": " + properties[propName] + "\n";
+    propertiesString += "[" + propName + "]: [" + properties[propName] + "]\n";
   }
   return propertiesString;
 }
@@ -294,7 +237,6 @@ function prettyPrintArray(array) {
 
 this.LogParser = {
   parseLogArray: parseLogArray,
-  parsePropertiesArray: parsePropertiesArray,
   prettyPrintArray: prettyPrintArray,
   prettyPrintLogArray: prettyPrintLogArray,
   prettyPrintPropertiesArray: prettyPrintPropertiesArray

b2g/components/LogShake.jsm

@@ -79,7 +79,6 @@ let LogShake = {
    * Map of files which have log-type information to their parsers
    */
   LOGS_WITH_PARSERS: {
-    '/dev/__properties__': LogParser.prettyPrintPropertiesArray,
     '/dev/log/main': LogParser.prettyPrintLogArray,
     '/dev/log/system': LogParser.prettyPrintLogArray,
     '/dev/log/radio': LogParser.prettyPrintLogArray,
@@ -210,6 +209,14 @@ let LogShake = {
    */
   readLogs: function() {
     let logArrays = {};
+
+    try {
+      logArrays["properties"] =
+        LogParser.prettyPrintPropertiesArray(LogCapture.readProperties());
+    } catch (ex) {
+      Cu.reportError("Unable to get device properties: " + ex);
+    }
+
     for (let loc in this.LOGS_WITH_PARSERS) {
       let logArray;
       try {

b2g/components/test/unit/test_logcapture.js

@@ -8,7 +8,7 @@
  * log devices
  */
 function run_test() {
-  Components.utils.import('resource:///modules/LogCapture.jsm');
+  Components.utils.import("resource:///modules/LogCapture.jsm");
 
   function verifyLog(log) {
     // log exists
@@ -17,9 +17,14 @@ function run_test() {
     ok(log.length >= 0);
   }
 
-  let mainLog = LogCapture.readLogFile('/dev/log/main');
+  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');
+  let meminfoLog = LogCapture.readLogFile("/proc/meminfo");
   verifyLog(meminfoLog);
 }

b2g/components/test/unit/test_logparser.js

@@ -2,48 +2,73 @@
 
 const {utils: Cu, classes: Cc, interfaces: Ci} = Components;
 
+function debug(msg) {
+  var timestamp = Date.now();
+  dump("LogParser: " + timestamp + ": " + msg + "\n");
+}
+
 function run_test() {
-  Cu.import('resource:///modules/LogParser.jsm');
-
-  let propertiesFile = do_get_file('data/test_properties');
-  let loggerFile = do_get_file('data/test_logger_file');
-
-  let propertiesStream = makeStream(propertiesFile);
-  let loggerStream = makeStream(loggerFile);
-
-  // Initialize arrays to hold the file contents (lengths are hardcoded)
-  let propertiesArray = new Uint8Array(propertiesStream.readByteArray(65536));
-  let loggerArray = new Uint8Array(loggerStream.readByteArray(4037));
-
-  propertiesStream.close();
-  loggerStream.close();
-
-  let properties = LogParser.parsePropertiesArray(propertiesArray);
-  let logMessages = LogParser.parseLogArray(loggerArray);
-
-  // Test arbitrary property entries for correctness
-  equal(properties['ro.boot.console'], 'ttyHSL0');
-  equal(properties['net.tcp.buffersize.lte'],
-        '524288,1048576,2097152,262144,524288,1048576');
-
-  ok(logMessages.length === 58, 'There should be 58 messages in the log');
-
-  let expectedLogEntry = {
-    processId: 271, threadId: 271,
-    seconds: 790796, nanoseconds: 620000001, time: 790796620.000001,
-    priority: 4, tag: 'Vold',
-    message: 'Vold 2.1 (the revenge) firing up\n'
-  };
-
-  deepEqual(expectedLogEntry, logMessages[0]);
+  Cu.import("resource:///modules/LogParser.jsm");
+  debug("Starting");
+  run_next_test();
 }
 
 function makeStream(file) {
-  var fileStream = Cc['@mozilla.org/network/file-input-stream;1']
+  var fileStream = Cc["@mozilla.org/network/file-input-stream;1"]
                 .createInstance(Ci.nsIFileInputStream);
   fileStream.init(file, -1, -1, 0);
-  var bis = Cc['@mozilla.org/binaryinputstream;1']
+  var bis = Cc["@mozilla.org/binaryinputstream;1"]
                 .createInstance(Ci.nsIBinaryInputStream);
   bis.setInputStream(fileStream);
   return bis;
 }
+
+add_test(function test_parse_logfile() {
+  let loggerFile = do_get_file("data/test_logger_file");
+
+  let loggerStream = makeStream(loggerFile);
+
+  // Initialize arrays to hold the file contents (lengths are hardcoded)
+  let loggerArray = new Uint8Array(loggerStream.readByteArray(4037));
+
+  loggerStream.close();
+
+  let logMessages = LogParser.parseLogArray(loggerArray);
+
+  ok(logMessages.length === 58, "There should be 58 messages in the log");
+
+  let expectedLogEntry = {
+    processId: 271, threadId: 271,
+    seconds: 790796, nanoseconds: 620000001, time: 790796620.000001,
+    priority: 4, tag: "Vold",
+    message: "Vold 2.1 (the revenge) firing up\n"
+  };
+
+  deepEqual(expectedLogEntry, logMessages[0]);
+  run_next_test();
+});
+
+add_test(function test_print_properties() {
+  let properties = {
+    "ro.secure": "1",
+    "sys.usb.state": "diag,serial_smd,serial_tty,rmnet_bam,mass_storage,adb"
+  };
+
+  let logMessages = LogParser.prettyPrintPropertiesArray(properties);
+  let logMessagesArray = logMessages.split("\n");
+
+  ok(logMessagesArray.length === 3, "There should be 3 lines in the log.");
+  notEqual(logMessagesArray[0], "", "First line should not be empty");
+  notEqual(logMessagesArray[1], "", "Second line should not be empty");
+  equal(logMessagesArray[2], "", "Last line should be empty");
+
+  let expectedLog = [
+    "[ro.secure]: [1]",
+    "[sys.usb.state]: [diag,serial_smd,serial_tty,rmnet_bam,mass_storage,adb]",
+    ""
+  ].join("\n");
+
+  deepEqual(expectedLog, logMessages);
+
+  run_next_test();
+});

b2g/components/test/unit/test_logshake.js

@@ -8,19 +8,19 @@
 
 /* disable use strict warning */
 /* jshint -W097 */
-'use strict';
+"use strict";
 
 const Cu = Components.utils;
 
-Cu.import('resource://gre/modules/LogCapture.jsm');
-Cu.import('resource://gre/modules/LogShake.jsm');
+Cu.import("resource://gre/modules/LogCapture.jsm");
+Cu.import("resource://gre/modules/LogShake.jsm");
 
 // Force logshake to handle a device motion event with given components
 // Does not use SystemAppProxy because event needs special
 // accelerationIncludingGravity property
 function sendDeviceMotionEvent(x, y, z) {
   let event = {
-    type: 'devicemotion',
+    type: "devicemotion",
     accelerationIncludingGravity: {
       x: x,
       y: y,
@@ -34,7 +34,7 @@ function sendDeviceMotionEvent(x, y, z) {
 // conditions.
 function sendScreenChangeEvent(screenEnabled) {
   let event = {
-    type: 'screenchange',
+    type: "screenchange",
     detail: {
       screenEnabled: screenEnabled
     }
@@ -44,7 +44,7 @@ function sendScreenChangeEvent(screenEnabled) {
 
 function debug(msg) {
   var timestamp = Date.now();
-  dump('LogShake: ' + timestamp + ': ' + msg);
+  dump("LogShake: " + timestamp + ": " + msg);
 }
 
 add_test(function test_do_log_capture_after_shaking() {
@@ -61,7 +61,7 @@ add_test(function test_do_log_capture_after_shaking() {
   sendDeviceMotionEvent(9001, 9001, 9001);
 
   ok(readLocations.length > 0,
-      'LogShake should attempt to read at least one log');
+      "LogShake should attempt to read at least one log");
 
   LogShake.uninit();
   run_next_test();
@@ -81,15 +81,15 @@ add_test(function test_do_nothing_when_resting() {
   sendDeviceMotionEvent(0, 9.8, 9.8);
 
   ok(readLocations.length === 0,
-      'LogShake should not read any logs');
+      "LogShake should not read any logs");
 
-  debug('test_do_nothing_when_resting: stop');
+  debug("test_do_nothing_when_resting: stop");
   LogShake.uninit();
   run_next_test();
 });
 
 add_test(function test_do_nothing_when_disabled() {
-  debug('test_do_nothing_when_disabled: start');
+  debug("test_do_nothing_when_disabled: start");
   // Disable LogShake
   LogShake.uninit();
 
@@ -103,7 +103,7 @@ add_test(function test_do_nothing_when_disabled() {
   sendDeviceMotionEvent(0, 9001, 9001);
 
   ok(readLocations.length === 0,
-      'LogShake should not read any logs');
+      "LogShake should not read any logs");
 
   run_next_test();
 });
@@ -126,7 +126,7 @@ add_test(function test_do_nothing_when_screen_off() {
   sendDeviceMotionEvent(0, 9001, 9001);
 
   ok(readLocations.length === 0,
-      'LogShake should not read any logs');
+      "LogShake should not read any logs");
 
   // Restore the screen
   sendScreenChangeEvent(true);
@@ -149,7 +149,7 @@ add_test(function test_do_log_capture_resilient_readLogFile() {
   sendDeviceMotionEvent(9001, 9001, 9001);
 
   ok(readLocations.length > 0,
-      'LogShake should attempt to read at least one log');
+      "LogShake should attempt to read at least one log");
 
   LogShake.uninit();
   run_next_test();
@@ -172,13 +172,13 @@ add_test(function test_do_log_capture_resilient_parseLog() {
   sendDeviceMotionEvent(9001, 9001, 9001);
 
   ok(readLocations.length > 0,
-      'LogShake should attempt to read at least one log');
+      "LogShake should attempt to read at least one log");
 
   LogShake.uninit();
   run_next_test();
 });
 
 function run_test() {
-  debug('Starting');
+  debug("Starting");
   run_next_test();
 }

b2g/components/test/unit/xpcshell.ini

@@ -4,7 +4,6 @@ tail =
 
 support-files =
   data/test_logger_file
-  data/test_properties
 
 [test_bug793310.js]