1 /*
2  * Copyright (C) 2023 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 android.adservices.test.scenario.adservices.topics;
18 
19 import static com.android.adservices.service.FlagsConstants.KEY_CLASSIFIER_FORCE_USE_BUNDLED_FILES;
20 
21 import static com.google.common.truth.Truth.assertThat;
22 
23 import android.adservices.clients.topics.AdvertisingTopicsClient;
24 import android.adservices.topics.GetTopicsResponse;
25 import android.adservices.topics.Topic;
26 import android.content.Context;
27 import android.platform.test.scenario.annotation.Scenario;
28 import android.util.Log;
29 
30 import androidx.test.core.app.ApplicationProvider;
31 import androidx.test.filters.FlakyTest;
32 
33 import com.android.adservices.common.AdServicesFlagsSetterRule;
34 import com.android.adservices.common.AdservicesTestHelper;
35 import com.android.compatibility.common.util.ShellUtils;
36 
37 import org.junit.Before;
38 import org.junit.Rule;
39 import org.junit.Test;
40 import org.junit.runner.RunWith;
41 import org.junit.runners.JUnit4;
42 
43 import java.io.BufferedReader;
44 import java.io.IOException;
45 import java.io.InputStream;
46 import java.io.InputStreamReader;
47 import java.text.ParseException;
48 import java.text.SimpleDateFormat;
49 import java.time.Clock;
50 import java.time.Instant;
51 import java.time.ZoneId;
52 import java.time.format.DateTimeFormatter;
53 import java.util.Arrays;
54 import java.util.Date;
55 import java.util.HashMap;
56 import java.util.Map;
57 import java.util.concurrent.Executor;
58 import java.util.concurrent.Executors;
59 
60 /** Crystalball test for Topics API to test epoch computation using the Precomputed classifier. */
61 @Scenario
62 @RunWith(JUnit4.class)
63 public class TopicsEpochComputationPrecomputedClassifier {
64     private static final String TAG = "TopicsEpochComputation";
65 
66     // Metric name for Crystalball test
67     private static final String EPOCH_COMPUTATION_DURATION = "EPOCH_COMPUTATION_DURATION";
68 
69     // The JobId of the Epoch Computation.
70     private static final int EPOCH_JOB_ID = 2;
71 
72     // Override the Epoch Job Period to this value to speed up the epoch computation.
73     private static final long TEST_EPOCH_JOB_PERIOD_MS = 3000;
74 
75     // Default Epoch Period.
76     private static final long TOPICS_EPOCH_JOB_PERIOD_MS = 7 * 86_400_000; // 7 days.
77 
78     // Use 0 percent for random topic in the test so that we can verify the returned topic.
79     private static final int TEST_TOPICS_PERCENTAGE_FOR_RANDOM_TOPIC = 0;
80     private static final int TOPICS_PERCENTAGE_FOR_RANDOM_TOPIC = 5;
81 
82     protected static final Context sContext = ApplicationProvider.getApplicationContext();
83     private static final Executor CALLBACK_EXECUTOR = Executors.newCachedThreadPool();
84 
85     private static final String ADSERVICES_PACKAGE_NAME =
86             AdservicesTestHelper.getAdServicesPackageName(sContext, TAG);
87 
88     private static final DateTimeFormatter LOG_TIME_FORMATTER =
89             DateTimeFormatter.ofPattern("MM-dd HH:mm:ss.SSS").withZone(ZoneId.systemDefault());
90 
91     private static final String EPOCH_COMPUTATION_START_LOG = "Start of Epoch Computation";
92 
93     private static final String EPOCH_COMPUTATION_END_LOG = "End of Epoch Computation";
94 
95     private static final String EPOCH_START_TIMESTAMP_KEY = "start";
96 
97     private static final String EPOCH_STOP_TIMESTAMP_KEY = "end";
98 
99     @Rule
100     public final AdServicesFlagsSetterRule flags =
101             AdServicesFlagsSetterRule.forTopicsPerfTests(
102                             TEST_EPOCH_JOB_PERIOD_MS, TEST_TOPICS_PERCENTAGE_FOR_RANDOM_TOPIC)
103                     // Turn off MDD to avoid model mismatching
104                     .setMddBackgroundTaskKillSwitch(true)
105                     .setFlag(KEY_CLASSIFIER_FORCE_USE_BUNDLED_FILES, true);
106 
107     @Before
setup()108     public void setup() throws Exception {
109         // We need to skip 3 epochs so that if there is any usage from other test runs, it will
110         // not be used for epoch retrieval.
111         Thread.sleep(3 * TEST_EPOCH_JOB_PERIOD_MS);
112     }
113 
114     @Test
115     @FlakyTest(bugId = 290122696)
testEpochComputation()116     public void testEpochComputation() throws Exception {
117         // The Test App has 2 SDKs: sdk1 calls the Topics API and sdk2 does not.
118         // Sdk1 calls the Topics API.
119         AdvertisingTopicsClient advertisingTopicsClient1 =
120                 new AdvertisingTopicsClient.Builder()
121                         .setContext(sContext)
122                         .setSdkName("sdk1")
123                         .setExecutor(CALLBACK_EXECUTOR)
124                         .build();
125 
126         // At beginning, Sdk1 receives no topic.
127         GetTopicsResponse sdk1Result = advertisingTopicsClient1.getTopics().get();
128         assertThat(sdk1Result.getTopics()).isEmpty();
129 
130         Instant startTime = Clock.systemUTC().instant();
131         // Now force the Epoch Computation Job. This should be done in the same epoch for
132         // callersCanLearnMap to have the entry for processing.
133         forceEpochComputationJob();
134 
135         // Wait to the next epoch. We will not need to do this after we implement the fix in
136         // go/rb-topics-epoch-scheduling
137         Thread.sleep(TEST_EPOCH_JOB_PERIOD_MS);
138 
139         // calculate and log epoch computation duration after some delay so that epoch
140         // computation job is finished.
141         logEpochComputationDuration(startTime);
142 
143         // Since the sdk1 called the Topics API in the previous Epoch, it should receive some topic.
144         sdk1Result = advertisingTopicsClient1.getTopics().get();
145         assertThat(sdk1Result.getTopics()).isNotEmpty();
146 
147         // We only have 1 test app which has 5 classification topics: 10147,10253,10175,10254,10333
148         // in the precomputed list.
149         // These 5 classification topics will become top 5 topics of the epoch since there is
150         // no other apps calling Topics API.
151         // The app will be assigned one random topic from one of these 5 topics.
152         assertThat(sdk1Result.getTopics()).hasSize(1);
153         Topic topic = sdk1Result.getTopics().get(0);
154 
155         // topic is one of the 5 classification topics of the Test App.
156         assertThat(topic.getTopicId()).isIn(Arrays.asList(10147, 10253, 10175, 10254, 10333));
157 
158         assertThat(topic.getModelVersion()).isAtLeast(1L);
159         assertThat(topic.getTaxonomyVersion()).isAtLeast(1L);
160 
161         // Sdk 2 did not call getTopics API. So it should not receive any topic.
162         AdvertisingTopicsClient advertisingTopicsClient2 =
163                 new AdvertisingTopicsClient.Builder()
164                         .setContext(sContext)
165                         .setSdkName("sdk2")
166                         .setExecutor(CALLBACK_EXECUTOR)
167                         .build();
168 
169         GetTopicsResponse sdk2Result2 = advertisingTopicsClient2.getTopics().get();
170         assertThat(sdk2Result2.getTopics()).isEmpty();
171     }
172 
173     /** Forces JobScheduler to run the Epoch Computation job */
forceEpochComputationJob()174     private void forceEpochComputationJob() {
175         ShellUtils.runShellCommand(
176                 "cmd jobscheduler run -f" + " " + ADSERVICES_PACKAGE_NAME + " " + EPOCH_JOB_ID);
177     }
178 
logEpochComputationDuration(Instant startTime)179     private void logEpochComputationDuration(Instant startTime) throws Exception {
180         long epoch_computation_duration =
181                 processLogCatStreamToGetMetricMap(getMetricsEvents(startTime));
182         Log.i(TAG, "(" + EPOCH_COMPUTATION_DURATION + ": " + epoch_computation_duration + ")");
183     }
184 
185     /** Return AdServices(EpochManager) logs that will be used to build the test metrics. */
getMetricsEvents(Instant startTime)186     public InputStream getMetricsEvents(Instant startTime) throws IOException {
187         ProcessBuilder pb =
188                 new ProcessBuilder(
189                         Arrays.asList(
190                                 "logcat",
191                                 "-s",
192                                 "adservices.topics:V",
193                                 "-t",
194                                 LOG_TIME_FORMATTER.format(startTime),
195                                 "|",
196                                 "grep",
197                                 "Epoch"));
198         return pb.start().getInputStream();
199     }
200 
201     /**
202      * Filters the start and end log for the epoch computation and based on that calculates the
203      * duration of epoch computation. If we fail to parse the start or end log for epoch
204      * computation, we catch ParseException and in the end throw an exception.
205      *
206      * @param inputStream the logcat stream which contains start and end time info for the epoch
207      *     computation
208      * @return the value of epoch computation latency
209      * @throws Exception if the test failed to get the time point for epoch computation's start and
210      *     end.
211      */
processLogCatStreamToGetMetricMap(InputStream inputStream)212     private Long processLogCatStreamToGetMetricMap(InputStream inputStream) throws Exception {
213         BufferedReader bufferedReader = new BufferedReader(new InputStreamReader(inputStream));
214         Map<String, Long> output = new HashMap<String, Long>();
215         bufferedReader
216                 .lines()
217                 .filter(
218                         line ->
219                                 line.contains(EPOCH_COMPUTATION_START_LOG)
220                                         || line.contains(EPOCH_COMPUTATION_END_LOG))
221                 .forEach(
222                         line -> {
223                             if (line.contains(EPOCH_COMPUTATION_START_LOG)) {
224                                 try {
225                                     output.put(
226                                             EPOCH_START_TIMESTAMP_KEY, getTimestampFromLog(line));
227                                 } catch (ParseException e) {
228                                     Log.e(
229                                             TAG,
230                                             String.format(
231                                                     "Caught ParseException when fetching start"
232                                                             + " time for epoch computation: %s",
233                                                     e.toString()));
234                                 }
235                             } else {
236                                 try {
237                                     output.put(EPOCH_STOP_TIMESTAMP_KEY, getTimestampFromLog(line));
238                                 } catch (ParseException e) {
239                                     Log.e(
240                                             TAG,
241                                             String.format(
242                                                     "Caught ParseException when fetching end time"
243                                                             + " for epoch computation: %s",
244                                                     e.toString()));
245                                 }
246                             }
247                         });
248 
249         if (output.containsKey(EPOCH_START_TIMESTAMP_KEY)
250                 && output.containsKey(EPOCH_STOP_TIMESTAMP_KEY)) {
251             return output.get(EPOCH_STOP_TIMESTAMP_KEY) - output.get(EPOCH_START_TIMESTAMP_KEY);
252         }
253         throw new Exception("Cannot get the time of Epoch Computation's start and end");
254     }
255 
256     /**
257      * Parses the timestamp from the log. Example log: 10-06 17:58:20.173 14950 14966 D adservices:
258      * Start of Epoch Computation
259      */
getTimestampFromLog(String log)260     private static Long getTimestampFromLog(String log) throws ParseException {
261         String[] words = log.split(" ");
262         SimpleDateFormat dateFormat = new SimpleDateFormat("MM-dd hh:mm:ss.SSS");
263         Date parsedDate = dateFormat.parse(words[0] + " " + words[1]);
264         return parsedDate.getTime();
265     }
266 }
267