Home | History | Annotate | Download | only in util
      1 /*
      2  * Copyright (C) 2016 The Android Open Source Project
      3  *
      4  * Licensed under the Apache License, Version 2.0 (the "License");
      5  * you may not use this file except in compliance with the License.
      6  * You may obtain a copy of the License at
      7  *
      8  *      http://www.apache.org/licenses/LICENSE-2.0
      9  *
     10  * Unless required by applicable law or agreed to in writing, software
     11  * distributed under the License is distributed on an "AS IS" BASIS,
     12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
     13  * See the License for the specific language governing permissions and
     14  * limitations under the License.
     15  */
     16 
     17 package com.android.tradefed.util;
     18 
     19 import com.android.tradefed.device.ILogcatReceiver;
     20 import com.android.tradefed.result.InputStreamSource;
     21 import com.android.tradefed.util.LogcatUpdaterEventParser.AsyncUpdaterEvent;
     22 
     23 import junit.framework.TestCase;
     24 
     25 import org.easymock.EasyMock;
     26 
     27 import java.io.IOException;
     28 import java.io.InputStream;
     29 import java.io.PipedInputStream;
     30 import java.io.PipedOutputStream;
     31 
     32 /**
     33  * Unit tests for {@link LogcatUpdaterEventParser}.
     34  */
     35 public class LogcatUpdaterEventParserTest extends TestCase {
     36 
     37     private static final String[] LOGS_UPDATE_COMPLETE = {
     38         "11-11 00:00:00.001  123 321 I update_engine: foo bar baz\n",
     39         "11-11 00:00:00.001  123 321 I update_engine: foo bar baz\n",
     40         "11-11 00:00:00.001  123 321 I update_engine: foo bar baz\n",
     41         "11-11 00:00:00.001  123 321 I update_engine: foo bar baz\n",
     42         "11-11 00:00:00.001  123 321 I update_engine: Update successfully applied\n",
     43     };
     44     private static final String[] LOGS_ERROR = {
     45         "11-11 00:00:00.001  123 321 I update_engine: foo bar baz\n",
     46         "11-11 00:00:00.001  123 321 I update_engine: foo bar baz\n",
     47         "11-11 00:00:00.001  123 321 I update_engine: foo bar baz\n",
     48         "11-11 00:00:00.001  123 321 I update_engine: foo bar baz\n",
     49         "11-11 00:00:00.001  123 321 I update_engine_client: "
     50                 + "onPayloadApplicationComplete(ErrorCode::kPayloadTimestampError (51))\n",
     51     };
     52     private static final String[] LOGS_ERROR_FLAKY = {
     53         "11-11 00:00:00.001  123 321 I update_engine: "
     54                 + "ActionProcessor: Aborting processing due to failure.\n",
     55         "11-11 00:00:00.001  123 321 I update_engine_client: "
     56                 + "onPayloadApplicationComplete(ErrorCode::kNewRootfsVerificationError (15))\n",
     57     };
     58     private static final long EVENT_TIMEOUT_MS = 5 * 1000L;
     59     private static final long THREAD_TIMEOUT_MS = 5 * 1000L;
     60 
     61     private ILogcatReceiver mMockReceiver = null;
     62     private LogcatUpdaterEventParser mParser = null;
     63     private PipedOutputStream mMockPipe = null;
     64 
     65     @Override
     66     public void setUp() {
     67         mMockReceiver = EasyMock.createMock(ILogcatReceiver.class);
     68         mMockPipe = new PipedOutputStream();
     69         final PipedInputStream p = new PipedInputStream();
     70         try {
     71             mMockPipe.connect(p);
     72         } catch (IOException e) {
     73             throw new RuntimeException(e);
     74         }
     75 
     76         EasyMock.expect(mMockReceiver.getLogcatData())
     77                 .andReturn(
     78                         new InputStreamSource() {
     79                             @Override
     80                             public InputStream createInputStream() {
     81                                 return p;
     82                             }
     83 
     84                             @Override
     85                             public void close() {
     86                                 // ignore
     87                             }
     88 
     89                             @Override
     90                             public long size() {
     91                                 return 0;
     92                             }
     93                         });
     94 
     95         EasyMock.replay(mMockReceiver);
     96         mParser = new LogcatUpdaterEventParser(mMockReceiver);
     97     }
     98 
     99     /**
    100      * Test that a known event parses to the expected {@link UpdaterEventType} when there is an
    101      * exact match.
    102      */
    103     public void testParseEventTypeExactMatch() {
    104         String mappedLogLine =
    105                 "11-11 00:00:00.001  123 321 I update_verifier: Leaving update_verifier.";
    106         assertEquals(
    107                 UpdaterEventType.UPDATE_VERIFIER_COMPLETE, mParser.parseEventType(mappedLogLine));
    108     }
    109 
    110     /**
    111      * Test that a known event parses to the expected {@link UpdaterEventType} when the registered
    112      * message is a substring of the log message.
    113      */
    114     public void testParseEventTypePartialMatch() {
    115         String log =
    116                 "01-09 17:06:50.799  8688  8688 I update_engine_client: "
    117                         + "onPayloadApplicationComplete(ErrorCode::kUserCanceled (48))";
    118         assertEquals(UpdaterEventType.ERROR, mParser.parseEventType(log));
    119     }
    120 
    121     /** Test that unknown events parse to null. */
    122     public void testParseEventTypeUnknown() {
    123         String unmappedLogLine = "11-11 00:00:00.001  123 321 I update_engine: foo bar baz";
    124         assertEquals(null, mParser.parseEventType(unmappedLogLine));
    125         unmappedLogLine = "11-11 00:00:00.001  123 321 I foobar_engine: Update succeeded";
    126         assertEquals(null, mParser.parseEventType(unmappedLogLine));
    127         unmappedLogLine = "11-11 00:00:00.001  123 321 I foobar_engine: foo bar baz";
    128         assertEquals(null, mParser.parseEventType(unmappedLogLine));
    129     }
    130 
    131     /** Test that parser recognize update engine error message */
    132     public void testParseEventTypeError() {
    133         String error1 =
    134                 "01-09 17:06:50.799  8688  8688 I update_engine_client: "
    135                         + "onPayloadApplicationComplete(ErrorCode::kUserCanceled (48))";
    136         assertEquals(UpdaterEventType.ERROR, mParser.parseEventType(error1));
    137     }
    138 
    139     /** Test that events registered first are matched first */
    140     public void testParseEventTypeMatchOrder() {
    141         mParser.registerEventTrigger(
    142                 "update_engine",
    143                 "finished with ErrorCode::kSuccess",
    144                 UpdaterEventType.PATCH_COMPLETE);
    145         mParser.registerEventTrigger(
    146                 "update_engine", "finished with ErrorCode", UpdaterEventType.ERROR);
    147         String notError =
    148                 "11-11 00:00:00.001  123 321 I update_engine: finished with ErrorCode::kSuccess";
    149         assertEquals(UpdaterEventType.PATCH_COMPLETE, mParser.parseEventType(notError));
    150     }
    151 
    152     /** Test that waitForEvent returns once it sees a specific expect event. */
    153     public void testWaitForEvent() throws Exception {
    154         feedMockPipe(LOGS_UPDATE_COMPLETE);
    155         UpdaterEventType result =
    156                 mParser.waitForEvent(UpdaterEventType.UPDATE_COMPLETE, EVENT_TIMEOUT_MS);
    157         assertEquals(UpdaterEventType.UPDATE_COMPLETE, result);
    158     }
    159 
    160     /** Test that waitForEvent returns when it sees an update error. */
    161     public void testWaitForEventError() throws Exception {
    162         feedMockPipe(LOGS_ERROR);
    163         UpdaterEventType event =
    164                 mParser.waitForEvent(UpdaterEventType.UPDATE_COMPLETE, EVENT_TIMEOUT_MS);
    165         assertEquals(UpdaterEventType.ERROR, event);
    166     }
    167 
    168     /** Test that waitForEvent returns when it sees an flaky update error. */
    169     public void testWaitForEventErrorFlaky() throws Exception {
    170         feedMockPipe(LOGS_ERROR_FLAKY);
    171         UpdaterEventType event =
    172                 mParser.waitForEvent(UpdaterEventType.UPDATE_COMPLETE, EVENT_TIMEOUT_MS);
    173         assertEquals(UpdaterEventType.ERROR_FLAKY, event);
    174     }
    175 
    176     /** Test that waitForEvent honors the timeout. */
    177     public void testWaitForEventTimeout() throws Exception {
    178         feedMockPipe(LOGS_UPDATE_COMPLETE);
    179         UpdaterEventType event = mParser.waitForEvent(UpdaterEventType.UPDATE_COMPLETE, 0);
    180         assertEquals(UpdaterEventType.INFRA_TIMEOUT, event);
    181     }
    182 
    183     /** Test that waitForEventAsync completes when it sees a specific expect event. */
    184     public void testWaitForEventAsync() throws Exception {
    185         AsyncUpdaterEvent event =
    186                 mParser.waitForEventAsync(UpdaterEventType.UPDATE_COMPLETE, EVENT_TIMEOUT_MS);
    187         feedMockPipe(LOGS_UPDATE_COMPLETE);
    188         event.waitUntilCompleted(THREAD_TIMEOUT_MS);
    189         assertEquals(UpdaterEventType.UPDATE_COMPLETE, event.getResult());
    190     }
    191 
    192     /** Test that waitForEventAsync completes when it sees an update error. */
    193     public void testWaitForEventAsyncError() throws Exception {
    194         AsyncUpdaterEvent event =
    195                 mParser.waitForEventAsync(UpdaterEventType.UPDATE_COMPLETE, EVENT_TIMEOUT_MS);
    196         feedMockPipe(LOGS_ERROR);
    197         event.waitUntilCompleted(THREAD_TIMEOUT_MS);
    198         assertEquals(UpdaterEventType.ERROR, event.getResult());
    199     }
    200 
    201     /** Test that waitForEventAsync honors the timeout. */
    202     public void testWaitForEventAsyncTimeout() throws Exception {
    203         AsyncUpdaterEvent event = mParser.waitForEventAsync(UpdaterEventType.UPDATE_COMPLETE, 0);
    204         feedMockPipe(LOGS_UPDATE_COMPLETE);
    205         event.waitUntilCompleted(THREAD_TIMEOUT_MS);
    206         assertEquals(UpdaterEventType.INFRA_TIMEOUT, event.getResult());
    207     }
    208 
    209     private void feedMockPipe(String[] logLines) {
    210         for (String line : logLines) {
    211             try {
    212                 mMockPipe.write(line.getBytes());
    213             } catch (IOException e) {
    214                 fail(e.getLocalizedMessage());
    215             }
    216         }
    217     }
    218 }
    219 
    220