diff options
Diffstat (limited to 'tests')
3 files changed, 16 insertions, 365 deletions
diff --git a/tests/src/com/android/loganalysis/UnitTests.java b/tests/src/com/android/loganalysis/UnitTests.java index 35359ba..68d5bf6 100644 --- a/tests/src/com/android/loganalysis/UnitTests.java +++ b/tests/src/com/android/loganalysis/UnitTests.java @@ -37,7 +37,6 @@ import com.android.loganalysis.parser.BatteryDischargeStatsInfoParserTest; import com.android.loganalysis.parser.BatteryStatsDetailedInfoParserTest; import com.android.loganalysis.parser.BatteryStatsSummaryInfoParserTest; import com.android.loganalysis.parser.BatteryUsageParserTest; -import com.android.loganalysis.parser.TimingsLogParserTest; import com.android.loganalysis.parser.BugreportParserTest; import com.android.loganalysis.parser.CompactMemInfoParserTest; import com.android.loganalysis.parser.CpuInfoParserTest; @@ -125,7 +124,6 @@ import org.junit.runners.Suite.SuiteClasses; BatteryStatsDetailedInfoParserTest.class, BatteryStatsSummaryInfoParserTest.class, BatteryUsageParserTest.class, - TimingsLogParserTest.class, BugreportParserTest.class, CompactMemInfoParserTest.class, CpuInfoParserTest.class, diff --git a/tests/src/com/android/loganalysis/parser/DmesgParserTest.java b/tests/src/com/android/loganalysis/parser/DmesgParserTest.java index 4362c7a..7cdbd36 100644 --- a/tests/src/com/android/loganalysis/parser/DmesgParserTest.java +++ b/tests/src/com/android/loganalysis/parser/DmesgParserTest.java @@ -215,15 +215,22 @@ public class DmesgParserTest extends TestCase { private static List<DmesgActionInfoItem> getExpectedActionInfoItems() { return Arrays.asList( - new DmesgActionInfoItem("/init.rc:13", "early-init", 44942L), - new DmesgActionInfoItem("<Builtin Action>:0", "set_mmap_rnd_bits", 47233L), - new DmesgActionInfoItem("<Builtin Action>:0", "set_kptr_restrict", 47240L), - new DmesgActionInfoItem("<Builtin Action>:0", "keychord_init", 47245L), - new DmesgActionInfoItem("<Builtin Action>:0", "persist.sys.usb.config=* boot", 52361L), - new DmesgActionInfoItem("<Builtin Action>:0", "enable_property_trigger", 52361L), - new DmesgActionInfoItem("/init.rc:677", "security.perf_harden=1", 52361L), - new DmesgActionInfoItem("/init.rc:700", "ro.debuggable=1", 52361L), - new DmesgActionInfoItem(null, "sys.boot_completed=1", 58298L)); + new DmesgActionInfoItem("early-init", (long) (Double.parseDouble("44942.872"))), + new DmesgActionInfoItem( + "set_mmap_rnd_bits", (long) (Double.parseDouble("47233.446"))), + new DmesgActionInfoItem( + "set_kptr_restrict", (long) (Double.parseDouble("47240.083"))), + new DmesgActionInfoItem("keychord_init", (long) (Double.parseDouble("47245.778"))), + new DmesgActionInfoItem( + "persist.sys.usb.config=* boot", (long) (Double.parseDouble("52361.049"))), + new DmesgActionInfoItem( + "enable_property_trigger", (long) (Double.parseDouble("52361.108"))), + new DmesgActionInfoItem( + "security.perf_harden=1", (long) (Double.parseDouble("52361.313"))), + new DmesgActionInfoItem( + "ro.debuggable=1", (long) (Double.parseDouble("52361.495"))), + new DmesgActionInfoItem( + "sys.boot_completed=1", (long) (Double.parseDouble("58298.293")))); } private static List<DmesgStageInfoItem> getExpectedStageInfoItems() { diff --git a/tests/src/com/android/loganalysis/parser/TimingsLogParserTest.java b/tests/src/com/android/loganalysis/parser/TimingsLogParserTest.java deleted file mode 100644 index 48881ea..0000000 --- a/tests/src/com/android/loganalysis/parser/TimingsLogParserTest.java +++ /dev/null @@ -1,354 +0,0 @@ -/* - * Copyright (C) 2019 The Android Open Source Project - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License - */ - -package com.android.loganalysis.parser; - -import com.android.loganalysis.item.GenericTimingItem; -import com.android.loganalysis.item.SystemServicesTimingItem; - -import junit.framework.TestCase; - -import java.io.BufferedReader; -import java.io.ByteArrayInputStream; -import java.io.IOException; -import java.io.InputStream; -import java.io.InputStreamReader; -import java.util.List; -import java.util.regex.Pattern; - -/** Unit Test for {@link TimingsLogParser} */ -public class TimingsLogParserTest extends TestCase { - - private TimingsLogParser mParser; - - public TimingsLogParserTest() { - mParser = new TimingsLogParser(); - } - - public void testParseGenericTiming_noPattern() throws IOException { - // Test when input is empty - String log = ""; - List<GenericTimingItem> items = mParser.parseGenericTimingItems(createBufferedReader(log)); - assertNotNull(items); - assertEquals(0, items.size()); - // Test when input is not empty - log = - String.join( - "\n", - "01-17 01:22:39.513 0 0 I CPU features: detected feature: GIC system register CPU interface", - "01-17 01:22:39.513 0 0 I CPU features: kernel page table isolation forced ON by command line option", - "01-17 01:22:39.513 0 0 I CPU features: detected feature: 32-bit EL0 Support", - "01-17 01:22:59.823 0 0 I init : Service 'bootanim' (pid 1030) exited with status 0", - "01-17 01:22:59.966 0 0 I init : processing action (sys.boot_completed=1) from (/init.rc:796)"); - items = mParser.parseGenericTimingItems(createBufferedReader(log)); - assertNotNull(items); - assertEquals(0, items.size()); - } - - public void testParseGenericTiming_multiplePattern_oneOccurrenceEach() throws IOException { - String log = - String.join( - "\n", - "01-17 01:22:39.503 0 0 I : Linux version 4.4.177 (Kernel Boot Started)", - "01-17 01:22:39.513 0 0 I CPU features: detected feature: GIC system register CPU interface", - "01-17 01:22:39.513 0 0 I CPU features: kernel page table isolation forced ON by command line option", - "01-17 01:22:39.513 0 0 I CPU features: detected feature: 32-bit EL0 Support", - "01-17 01:22:43.634 0 0 I init : starting service 'zygote'...", - "01-17 01:22:48.634 0 0 I init : 'zygote' started", - "01-17 01:22:53.392 0 0 I init : starting service 'fake service'", - "01-17 01:22:59.823 0 0 I init : Service 'bootanim' (pid 1030) exited with status 0", - "01-17 01:22:60.334 0 0 I init : 'fake service' started", - "01-17 01:22:61.362 938 1111 I ActivityManager: my app started", - "01-17 01:22:61.977 938 1111 I ActivityManager: my app displayed"); - - mParser.addDurationPatternPair( - "BootToAnimEnd", - Pattern.compile("Linux version"), - Pattern.compile("Service 'bootanim'")); - mParser.addDurationPatternPair( - "ZygoteStartTime", - Pattern.compile("starting service 'zygote'"), - Pattern.compile("'zygote' started")); - mParser.addDurationPatternPair( - "FakeServiceStartTime", - Pattern.compile("starting service 'fake service'"), - Pattern.compile("'fake service' started")); - mParser.addDurationPatternPair( - "BootToAppStart", - Pattern.compile("Linux version"), - Pattern.compile("my app displayed")); - mParser.addDurationPatternPair( - "AppStartTime", - Pattern.compile("my app started"), - Pattern.compile("my app displayed")); - mParser.addDurationPatternPair( - "ZygoteToApp", - Pattern.compile("'zygote' started"), - Pattern.compile("my app started")); - List<GenericTimingItem> items = mParser.parseGenericTimingItems(createBufferedReader(log)); - assertNotNull(items); - assertEquals(6, items.size()); - // 1st item - assertEquals("ZygoteStartTime", items.get(0).getName()); - assertEquals(5000.0, items.get(0).getDuration()); - // 2nd item - assertEquals("BootToAnimEnd", items.get(1).getName()); - assertEquals(20320.0, items.get(1).getDuration()); - // 3rd item - assertEquals("FakeServiceStartTime", items.get(2).getName()); - assertEquals(6942.0, items.get(2).getDuration()); - // 4th item - assertEquals("ZygoteToApp", items.get(3).getName()); - assertEquals(12728.0, items.get(3).getDuration()); - // 5th item - assertEquals("BootToAppStart", items.get(4).getName()); - assertEquals(22474.0, items.get(4).getDuration()); - // 6th item - assertEquals("AppStartTime", items.get(5).getName()); - assertEquals(615.0, items.get(5).getDuration()); - } - - public void testParseGenericTiming_multiplePattern_someNotMatched() throws IOException { - String log = - String.join( - "\n", - "01-17 01:22:39.503 0 0 I : Linux version 4.4.177 (Kernel Boot Started)", - "01-17 01:22:39.513 0 0 I CPU features: detected feature: GIC system register CPU interface", - "01-17 01:22:39.513 0 0 I CPU features: kernel page table isolation forced ON by command line option", - "01-17 01:22:39.513 0 0 I CPU features: detected feature: 32-bit EL0 Support", - "01-17 01:22:43.634 0 0 I init : starting service 'zygote'...", - "01-17 01:22:48.634 0 0 I init : 'zygote' started", - "01-17 01:22:53.392 0 0 I init : starting service 'fake service'", - "01-17 01:22:59.823 0 0 I init : Service 'bootanim' (pid 1030) exited with status 0", - "01-17 01:22:60.334 0 0 I init : 'fake service' started", - "01-17 01:22:61.362 938 1111 I ActivityManager: my app started", - "01-17 01:22:61.977 938 1111 I ActivityManager: my app displayed"); - - mParser.addDurationPatternPair( - "BootToAnimEnd", - Pattern.compile("Linux version"), - Pattern.compile("Service 'bootanim'")); - mParser.addDurationPatternPair( - "ZygoteStartTime", - Pattern.compile("starting service 'zygote'"), - Pattern.compile("End line no there")); - mParser.addDurationPatternPair( - "FakeServiceStartTime", - Pattern.compile("Start line not there"), - Pattern.compile("'fake service' started")); - mParser.addDurationPatternPair( - "AppStartTime", - Pattern.compile("Start line not there"), - Pattern.compile("End line not there")); - - List<GenericTimingItem> items = mParser.parseGenericTimingItems(createBufferedReader(log)); - assertNotNull(items); - assertEquals(1, items.size()); - assertEquals("BootToAnimEnd", items.get(0).getName()); - } - - public void testParseGenericTiming_clearExistingPatterns() throws IOException { - String log = - String.join( - "\n", - "01-17 01:22:39.503 0 0 I : Linux version 4.4.177 (Kernel Boot Started)", - "01-17 01:22:53.392 0 0 I init : starting service 'fake service'", - "01-17 01:22:59.823 0 0 I init : Service 'bootanim' (pid 1030) exited with status 0", - "01-17 01:22:60.334 0 0 I init : 'fake service' started", - "01-17 01:22:61.362 938 1111 I ActivityManager: my app started", - "01-17 01:22:61.977 938 1111 I ActivityManager: my app displayed"); - mParser.addDurationPatternPair( - "BootToAnimEnd", - Pattern.compile("Linux version"), - Pattern.compile("Service 'bootanim'")); - List<GenericTimingItem> items = mParser.parseGenericTimingItems(createBufferedReader(log)); - assertNotNull(items); - assertEquals(1, items.size()); - - mParser.clearDurationPatterns(); - items = mParser.parseGenericTimingItems(createBufferedReader(log)); - assertNotNull(items); - assertEquals(0, items.size()); - } - - public void testParseGenericTiming_multiplePattern_multipleOccurrence() throws IOException { - String log = - String.join( - "\n", - "01-17 01:22:39.503 0 0 I : Linux version 4.4.177 (Kernel Boot Started)", - "01-17 01:22:39.513 0 0 I CPU features: detected feature: GIC system register CPU interface", - "01-17 01:22:39.513 0 0 I CPU features: kernel page table isolation forced ON by command line option", - "01-17 01:22:39.513 0 0 I CPU features: detected feature: 32-bit EL0 Support", - "01-17 01:22:43.634 0 0 I init : starting service 'zygote'...", - "01-17 01:22:48.634 0 0 I init : 'zygote' started", - "01-17 01:22:53.392 0 0 I init : starting service 'fake service'", - "01-17 01:22:59.823 0 0 I init : 'bootanim' not reported", - "01-17 01:22:60.334 0 0 I init : 'fake service' started", - "01-17 01:32:39.503 0 0 I : Linux version 4.4.177 (Kernel Boot Started)", - "01-17 01:32:39.513 0 0 I CPU features: detected feature: GIC system register CPU interface", - "01-17 01:32:39.513 0 0 I CPU features: kernel page table isolation forced ON by command line option", - "01-17 01:32:39.513 0 0 I CPU features: detected feature: 32-bit EL0 Support", - "01-17 01:32:43.634 0 0 I init : starting service 'zygote'...", - "01-17 01:32:48.634 0 0 I init : 'zygote' started", - "01-17 01:32:53.392 0 0 I init : starting service 'a different service'", - "01-17 01:32:59.823 0 0 I init : Service 'bootanim' (pid 1030) exited with status 0", - "01-17 01:32:60.334 0 0 I init : 'fake service' started", - "01-17 01:32:61.362 938 1111 I ActivityManager: my app started", - "01-17 01:32:61.977 938 1111 I ActivityManager: my app displayed"); - - mParser.addDurationPatternPair( - "BootToAnimEnd", - Pattern.compile("Linux version"), - Pattern.compile("Service 'bootanim'")); - mParser.addDurationPatternPair( - "ZygoteStartTime", - Pattern.compile("starting service 'zygote'"), - Pattern.compile("'zygote' started")); - mParser.addDurationPatternPair( - "FakeServiceStartTime", - Pattern.compile("starting service 'fake service'"), - Pattern.compile("'fake service' started")); - mParser.addDurationPatternPair( - "AppStartTime", - Pattern.compile("my app started"), - Pattern.compile("my app displayed")); - List<GenericTimingItem> items = mParser.parseGenericTimingItems(createBufferedReader(log)); - assertNotNull(items); - assertEquals(5, items.size()); - // 1st item - assertEquals("ZygoteStartTime", items.get(0).getName()); - assertEquals(5000.0, items.get(0).getDuration()); - // 2nd item - assertEquals("FakeServiceStartTime", items.get(1).getName()); - assertEquals(6942.0, items.get(1).getDuration()); - // 3rd item - assertEquals("ZygoteStartTime", items.get(2).getName()); - assertEquals(5000.0, items.get(2).getDuration()); - // 4th item - assertEquals("BootToAnimEnd", items.get(3).getName()); - assertEquals(20320.0, items.get(3).getDuration()); - // 5th item - assertEquals("AppStartTime", items.get(4).getName()); - assertEquals(615.0, items.get(4).getDuration()); - } - - public void testParseGenericTiming_wrongTimeFormat() throws IOException { - String log = - String.join( - "\n", - "1234252.234 0 0 I : Linux version 4.4.177 (Kernel Boot Started)", - "1234259.342 0 0 I CPU features: detected feature: GIC system register CPU interface"); - mParser.addDurationPatternPair( - "BootToAnimEnd", - Pattern.compile("Linux version"), - Pattern.compile("Service 'bootanim'")); - try { - List<GenericTimingItem> items = - mParser.parseGenericTimingItems(createBufferedReader(log)); - } catch (RuntimeException e) { - assertTrue( - "Test should report ParseException", - e.getCause().toString().startsWith("java.text.ParseException")); - return; - } - fail("Test should throw ParseException"); - } - - /** Test that system services duration can be parsed as expected */ - public void testParseSystemServicesTiming_system_services_duration() throws IOException { - String log = - String.join( - "\n", - "01-10 01:25:57.675 981 981 D SystemServerTiming: StartWatchdog took to complete: 38ms", - "01-10 01:25:57.675 981 981 I SystemServer: Reading configuration...", - "01-10 01:25:57.675 981 981 I SystemServer: ReadingSystemConfig", - "01-10 01:25:57.676 981 981 D SystemServerTiming: ReadingSystemConfig took to complete: 0.53ms", - "01-10 01:25:57.676 981 981 D SystemServerTiming: ReadingSystemConfig took to complete: 0.53ms", // Parser should skip duplicated log line - "01-10 01:25:57.677 465 465 I snet_event_log: [121035042,-1,]", - "01-10 01:25:57.678 900 900 I FakeComponent: FakeSubcomponent wrong format took to complete: 10ms", - "01-10 01:25:57.678 900 900 I FakeComponent: FakeSubcomponent took to complete: 20s", - "01-10 01:25:57.680 981 981 D SystemServerTiming: StartInstaller took to complete: 5ms wrong format", - "01-10 01:25:57.682 981 981 D SystemServerTiming: DeviceIdentifiersPolicyService took to complete: 2ms", - "01-10 01:25:57.682 981 981 D SystemServerTiming: DeviceIdentifiersPolicyService took to complete: 2ms", - "06-06 19:23:54.410 1295 1295 D OtherService : StartTestStack took to complete: 7ms", - "06-06 19:23:55.410 129 129 D FakeService : Validtook to complete: 8ms", - "06-06 19:23:56.410 981 981 D SystemServerTiming: StartWatchdog took to complete: 38ms"); //Parser should parse the same metric at a different time - - List<SystemServicesTimingItem> items = - mParser.parseSystemServicesTimingItems(createBufferedReader(log)); - assertNotNull(items); - assertEquals(6, items.size()); - assertEquals("SystemServerTiming", items.get(0).getComponent()); - assertEquals(38.0, items.get(0).getDuration()); - assertNull(items.get(0).getStartTime()); - assertEquals("ReadingSystemConfig", items.get(1).getSubcomponent()); - assertEquals(0.53, items.get(1).getDuration()); - assertNull(items.get(1).getStartTime()); - assertEquals("DeviceIdentifiersPolicyService", items.get(2).getSubcomponent()); - assertEquals("OtherService", items.get(3).getComponent()); - assertEquals("StartTestStack", items.get(3).getSubcomponent()); - assertEquals(7.0, items.get(3).getDuration()); - assertEquals("FakeService", items.get(4).getComponent()); - assertEquals("Valid", items.get(4).getSubcomponent()); - assertEquals(8.0, items.get(4).getDuration()); - assertNull(items.get(4).getStartTime()); - assertEquals("SystemServerTiming", items.get(5).getComponent()); - assertEquals("StartWatchdog", items.get(5).getSubcomponent()); - assertEquals(38.0, items.get(5).getDuration()); - } - - /** Test that system services start time can be parsed as expected */ - public void testParseSystemServicesTiming_system_services_start_time() throws IOException { - String log = - String.join( - "\n", - "01-10 01:24:45.536 1079 1079 D BootAnimation: BootAnimationStartTiming start time: 8611ms", - "01-10 01:24:45.537 1079 1079 D BootAnimation: BootAnimationPreloadTiming start time: 8611ms", - "01-10 01:24:45.556 874 1021 I ServiceManager: Waiting for service 'package_native' on '/dev/binder'...", - "01-10 01:24:45.561 466 466 I snet_event_log: [121035042,-1,]", - "01-10 01:24:45.583 1080 1080 I SystemServer: InitBeforeStartServices start time: 2345ms wrong format", - "01-10 01:25:24.095 1014 1111 D BootAnimation: BootAnimationShownTiming start time: 9191s", - "06-06 19:23:49.299 603 603 E qdmetadata: Unknown paramType 2", - "06-06 19:23:49.299 603 603 I FakeComponent : wrong subcomponent start time: 234ms", - "06-06 19:23:49.299 603 603 D FakeComponent: Subcomponent start time 234ms", - "06-06 19:23:49.299 1079 1079 D BootAnimation: BootAnimationStopTiming start time: 24839ms", - "06-06 19:23:59.299 179 179 D FakeService : Validstart time: 34839ms"); - - List<SystemServicesTimingItem> items = - mParser.parseSystemServicesTimingItems(createBufferedReader(log)); - assertNotNull(items); - assertEquals(4, items.size()); - assertEquals("BootAnimation", items.get(0).getComponent()); - assertEquals("BootAnimationStartTiming", items.get(0).getSubcomponent()); - assertEquals(8611.0, items.get(0).getStartTime()); - assertNull(items.get(0).getDuration()); - assertEquals("BootAnimationPreloadTiming", items.get(1).getSubcomponent()); - assertEquals("BootAnimation", items.get(2).getComponent()); - assertEquals("BootAnimationStopTiming", items.get(2).getSubcomponent()); - assertEquals(24839.0, items.get(2).getStartTime()); - assertNull(items.get(2).getDuration()); - assertEquals("FakeService", items.get(3).getComponent()); - assertEquals("Valid", items.get(3).getSubcomponent()); - assertEquals(34839.0, items.get(3).getStartTime()); - assertNull(items.get(3).getDuration()); - } - - private BufferedReader createBufferedReader(String input) { - InputStream inputStream = new ByteArrayInputStream(input.getBytes()); - InputStreamReader reader = new InputStreamReader(inputStream); - return new BufferedReader(reader); - } -} |