test/spec/LogHelperSpec.js

// Copyright 2015 The Chromium OS Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.

/**
 * @fileoverview Jasmine test file for log_helper.js.
 */

describe('LogHelper', function() {

  it('should convert elapsed ms to a wall time', function() {
    expect(logHelper.formatElapsedMS('1')).toEqual('00:00:00.001');
    expect(logHelper.formatElapsedMS('10')).toEqual('00:00:00.010');
    expect(logHelper.formatElapsedMS('100')).toEqual('00:00:00.100');
    expect(logHelper.formatElapsedMS('1000')).toEqual('00:00:01.000');
    expect(logHelper.formatElapsedMS('10000')).toEqual('00:00:10.000');
    expect(logHelper.formatElapsedMS('100000')).toEqual('00:01:40.000');
    expect(logHelper.formatElapsedMS('1000000')).toEqual('00:16:40.000');
    expect(logHelper.formatElapsedMS('10000000')).toEqual('02:46:40.000');
  });

  it('should detect syslogs', function() {
    var time1 = '2015-01-06T23:33:03.478905-08:00';
    var time2 = '2015-01-06T23:33:06.680764-08:00';
    var time3 = '2015-01-06T23:33:06.681832-08:00';

    var basicLog = [
        time1 + ' wpa_supplicant[863]: nl80211: Scan trigger',
        time2 + ' wpa_supplicant[863]: nl80211: Event message available',
        time3 + ' wpa_supplicant[863]: nl80211: New scan results available'
    ];
    var log;
    var logLines = [
        '---------- END ----------',
        '',
        'netlog=<multiline>',
        '---------- START ----------'
    ];
    log = logLines.concat(basicLog);
    log.push('---------- END ----------');
    log.push('');
    log.push('syslog=<multiline>');
    log.push('---------- START ----------');
    log.push(time1 + ' ERR shill[807]: [ERROR:wifi.cc(978)] Disconnected ' +
        'due to inability to connect to the service.');
    log.push('---------- END ----------');
    var logHolder = logHelper.detectFileType(log);
    expect(logHolder.fileType).toEqual('system_log');
    expect(logHolder.androidlog).not.toBeDefined();
    expect(logHolder.netlog.length).toEqual(3);
    expect(logHolder.syslog.length).toEqual(1);
    expect(logHolder.brillolog).not.toBeDefined();
  });

  it('should detect netlogs', function() {
    var time1 = '2015-01-06T23:33:03.478905-08:00';
    var time2 = '2015-01-06T23:33:06.680764-08:00';
    var time3 = '2015-01-06T23:33:06.681832-08:00';

    var basicLog = [
        time1 + ' Service 0 updated; state: Associating failure Unknown',
        time2 + ' Service 0: state Idle -> Associating',
        time3 + ' wpa_supplicant[863]: nl80211: New scan results available'
    ];
    var logHolder = logHelper.detectFileType(basicLog);
    expect(logHolder.fileType).toEqual('netlog');
    expect(logHolder.androidlog).not.toBeDefined();
    expect(logHolder.netlog.length).toEqual(3);
    expect(logHolder.syslog).not.toBeDefined();
    expect(logHolder.brillolog).not.toBeDefined();
  });

  it('should detect brillo logs', function() {
    var brilloLog = [
      '10-30 22:47:54.351   238   238 I /system/bin/shill: ' +
          'INFO:service.cc(407)] Service 2: state Associating -> Idle',
      '10-30 22:47:54.352   238   238 I /system/bin/shill: ' +
          '[INFO:manager.cc(1390)] Service 2 updated; ' +
          'state: Idle failure Unknown',
      '01-12 00:52:22.343     0     0 I wlan    : ' +
          'connection failed with 00:00:00:00:00:00 reason:1 and Status:9'
    ];
    var logHolder = logHelper.detectFileType(brilloLog);
    expect(logHolder.fileType).toEqual('brillolog');
    expect(logHolder.androidlog).not.toBeDefined();
    expect(logHolder.netlog).not.toBeDefined();
    expect(logHolder.syslog).not.toBeDefined();
    expect(logHolder.brillolog.length).toEqual(3);
  });

  it('should detect an unknown file type', function() {
    var randomFile = [
        'This is not a real log',
        'It should not be processed',
        ' wpa_supplicant[863]: nl80211: New scan results available'
    ];
    var logHolder = logHelper.detectFileType(randomFile);
    expect(logHolder.fileType).toEqual('unknown');
    expect(logHolder.androidlog).not.toBeDefined();
    expect(logHolder.netlog).not.toBeDefined();
    expect(logHolder.syslog).not.toBeDefined();
    expect(logHolder.brillolog).not.toBeDefined();
  });

  it('should detect an android bug report file', function() {
    var androidBugReport = [
        '========================================================',
        '== dumpstate: 2015-11-20 12:11:35',
        '========================================================',
        '',
        '--------- beginning of main',
        '11-20 12:08:06.463   489   897 D CommandListener: Setting iface cfg',
        '11-20 12:08:06.521   903  2909 D ConnectivityService: Adding iface ' +
            'wlan0 to network 169',
        '[logcat: 0.530s elapsed]',
        '',
        '------ EVENT LOG (logcat -b events -v threadtime -d *:v) -----',
    ];
    var logHolder = logHelper.detectFileType(androidBugReport);
    expect(logHolder.fileType).toEqual('android_log');
    expect(logHolder.androidlog.length).toEqual(2);
    expect(logHolder.netlog).not.toBeDefined();
    expect(logHolder.syslog).not.toBeDefined();
    expect(logHolder.brillolog).not.toBeDefined();
  });

  it('should ignore \"LAST LOGCAT\" section of android bug report file',
      function() {
    var androidBugReport = [
        '========================================================',
        '== dumpstate: 2015-11-20 12:11:35',
        '========================================================',
        '',
        'Build: bullhead-userdebug 6.0.1 MMB29B 2387154 dev-keys',
        '11-20 12:08:02.926   903  2909 D ConnectivityService: ' +
            ' sendStickyBroadcast: action=android.net.conn.CONNECTIVITY_CHANGE',
        '------ LAST LOGCAT (logcat -L -v threadtime -b all -d *:v) ------',
        '--------- beginning of main',
        '05-26 01:34:12.948   313   313 W libsuspend: Error writing \'on\'' +
            ' to /sys/power/state: Invalid argument',
        '[logcat: 0.015s elapsed]',
        '--------- beginning of main',
        '11-20 12:08:06.463   489   897 D CommandListener: Setting iface cfg',
        '11-20 12:08:06.521   903  2909 D ConnectivityService: Adding iface ' +
            'wlan0 to network 169',
        '[logcat: 0.530s elapsed]',
        '',
        '------ EVENT LOG (logcat -b events -v threadtime -d *:v) -----',
        '11-20 12:01:45.958  3432  9804 I gtalk_conn_close: [276,8]'
    ];
    var logHolder = logHelper.detectFileType(androidBugReport);
    expect(logHolder.fileType).toEqual('android_log');
    expect(logHolder.androidlog.length).toEqual(2);
    expect(logHolder.netlog).not.toBeDefined();
    expect(logHolder.syslog).not.toBeDefined();
    expect(logHolder.brillolog).not.toBeDefined();
  });


  it('should ignore info outside main subsection of android bug report file',
     function() {
    var androidBugReport = [
        '========================================================',
        '== dumpstate: 2015-11-20 12:11:35',
        '========================================================',
        '',
        'Build: bullhead-userdebug 6.0.1 MMB29B 2387154 dev-keys',
        '11-20 12:08:02.926   903  2909 D ConnectivityService: ' +
            ' sendStickyBroadcast: action=android.net.conn.CONNECTIVITY_CHANGE',
        '--------- beginning of main',
        '11-20 12:08:06.463   489   897 D CommandListener: Setting iface cfg',
        '11-20 12:08:06.521   903  2909 D ConnectivityService: Adding iface ' +
            'wlan0 to network 169',
        '[logcat: 0.530s elapsed]',
        '',
        '------ EVENT LOG (logcat -b events -v threadtime -d *:v) -----',
        '11-20 12:01:45.958  3432  9804 I gtalk_conn_close: [276,8]'
    ];
    var logHolder = logHelper.detectFileType(androidBugReport);
    expect(logHolder.fileType).toEqual('android_log');
    expect(logHolder.androidlog.length).toEqual(2);
    expect(logHolder.netlog).not.toBeDefined();
    expect(logHolder.syslog).not.toBeDefined();
    expect(logHolder.brillolog).not.toBeDefined();
  });

  it('should detect an android logcat file', function() {
    var androidBugReport = [
        '',
        '11-20 12:08:06.463   489   897 D CommandListener: Setting iface cfg',
        '11-20 12:08:06.521   903  2909 D ConnectivityService: Adding iface ' +
            'wlan0 to network 169'
    ];
    var logHolder = logHelper.detectFileType(androidBugReport);
    expect(logHolder.fileType).toEqual('android_log');
    expect(logHolder.androidlog.length).toEqual(3);
    expect(logHolder.netlog).not.toBeDefined();
    expect(logHolder.syslog).not.toBeDefined();
    expect(logHolder.brillolog).not.toBeDefined();
  });

  it('should properly determine log offsets', function() {
    var time1 = '2015-01-06T23:33:03.478905-08:00';
    var time2 = '2015-01-06T23:33:06.680764-08:30';
    var time3 = '2015-01-06T23:33:06.681832+04:00';
    var time4 = '2015-01-06T23:33:03.478905+04:30';
    var time5 = '2015-01-06T23:33:06.680764-00:00';
    var time6 = '2015-01-06T23:33:06.681832+00:00';

    var result = time1.match(logHelper.TIME_FORMAT);
    expect(result[1]).toEqual('-');
    expect(logHelper.getOffsetMS(result)).toEqual(-28800000);

    result = time2.match(logHelper.TIME_FORMAT);
    expect(result[1]).toEqual('-');
    expect(logHelper.getOffsetMS(result)).toEqual(-30600000);

    result = time3.match(logHelper.TIME_FORMAT);
    expect(result[1]).toEqual('+');
    expect(logHelper.getOffsetMS(result)).toEqual(14400000);

    result = time4.match(logHelper.TIME_FORMAT);
    expect(result[1]).toEqual('+');
    expect(logHelper.getOffsetMS(result)).toEqual(16200000);

    result = time5.match(logHelper.TIME_FORMAT);
    expect(result[1]).toEqual('-');
    var check = 0;
    var check2 = 0 * -1;
    expect(logHelper.getOffsetMS(result)).toEqual(0);

    result = time6.match(logHelper.TIME_FORMAT);
    expect(result[1]).toEqual('+');
    expect(logHelper.getOffsetMS(result)).toEqual(0);
  });
});