1 /*
2  * Copyright (C) 2020 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 #include "chre_audio_concurrency_test_manager.h"
18 
19 #include <pb_decode.h>
20 
21 #include "audio_validation.h"
22 #include "chre/util/nanoapp/log.h"
23 #include "chre/util/time.h"
24 #include "chre_audio_concurrency_test.nanopb.h"
25 #include "send_message.h"
26 
27 #define LOG_TAG "[ChreAudioConcurrencyTest]"
28 
29 namespace chre {
30 
31 using test_shared::checkAudioSamplesAllSame;
32 using test_shared::checkAudioSamplesAllZeros;
33 using test_shared::sendEmptyMessageToHost;
34 using test_shared::sendTestResultToHost;
35 
36 namespace audio_concurrency_test {
37 
38 namespace {
39 
40 //! The message type to use with sendTestResultToHost()
41 constexpr uint32_t kTestResultMessageType =
42     chre_audio_concurrency_test_MessageType_TEST_RESULT;
43 
44 //! The maximum number of samples that can be missed before triggering a suspend
45 //! event. 50 samples at a sample rate of 44100 (typical) is approximately 1 ms
46 //! of audio gap.
47 constexpr uint32_t kMaxMissedSamples = 50;
48 
isTestSupported()49 bool isTestSupported() {
50   // CHRE audio was supported in CHRE v1.2
51   return chreGetVersion() >= CHRE_API_VERSION_1_2;
52 }
53 
getTestStep(const chre_audio_concurrency_test_TestCommand & command,Manager::TestStep * step)54 bool getTestStep(const chre_audio_concurrency_test_TestCommand &command,
55                  Manager::TestStep *step) {
56   bool success = true;
57   switch (command.step) {
58     case chre_audio_concurrency_test_TestCommand_Step_ENABLE_AUDIO: {
59       *step = Manager::TestStep::ENABLE_AUDIO;
60       break;
61     }
62     case chre_audio_concurrency_test_TestCommand_Step_VERIFY_AUDIO_RESUME: {
63       *step = Manager::TestStep::VERIFY_AUDIO_RESUME;
64       break;
65     }
66     case chre_audio_concurrency_test_TestCommand_Step_ENABLE_AUDIO_WITH_GAP_VERIFICATION: {
67       *step = Manager::TestStep::ENABLE_AUDIO_WITH_GAP_VERIFICATION;
68       break;
69     }
70     default: {
71       LOGE("Unknown test step %d", command.step);
72       success = false;
73     }
74   }
75 
76   return success;
77 }
78 
79 }  // anonymous namespace
80 
~Manager()81 Manager::~Manager() {
82   if (mAudioEnabled) {
83     chreAudioConfigureSource(kAudioHandle, false /* enable */,
84                              0 /* bufferDuration */, 0 /* deliveryInterval */);
85   }
86   cancelTimeoutTimer();
87 }
88 
handleTestCommandMessage(uint16_t hostEndpointId,TestStep step)89 bool Manager::handleTestCommandMessage(uint16_t hostEndpointId, TestStep step) {
90   // Treat as success if CHRE audio is unsupported
91   // TODO: Use all available audio sources
92   if (!isTestSupported() || !chreAudioGetSource(kAudioHandle, &mAudioSource)) {
93     sendTestResultToHost(hostEndpointId, kTestResultMessageType,
94                          true /* success */);
95     return true;
96   }
97 
98   bool success = false;
99   switch (step) {
100     case TestStep::ENABLE_AUDIO_WITH_GAP_VERIFICATION:
101     case TestStep::ENABLE_AUDIO: {
102       mVerifyAudioGaps = step == TestStep::ENABLE_AUDIO_WITH_GAP_VERIFICATION;
103 
104       if (!chreAudioConfigureSource(kAudioHandle, true /* enable */,
105                                     mAudioSource.minBufferDuration,
106                                     mAudioSource.minBufferDuration)) {
107         LOGE("Failed to configure audio source");
108       } else {
109         mAudioEnabled = true;
110         // Start a timer to ensure we receive the first audio data event
111         // quickly. Since it may take some time to load the sound model, choose
112         // a reasonably long timeout.
113         success = setTimeoutTimer(20 /* durationSeconds */);
114       }
115       break;
116     }
117     case TestStep::VERIFY_AUDIO_RESUME: {
118       success = setTimeoutTimer(20 /* durationSeconds */);
119       break;
120     }
121     default: {
122       break;
123     }
124   }
125 
126   if (success) {
127     mTestSession = TestSession(hostEndpointId, step);
128     LOGI("Starting test step %" PRIu8,
129          static_cast<uint8_t>(mTestSession->step));
130   }
131 
132   return success;
133 }
134 
handleMessageFromHost(uint32_t senderInstanceId,const chreMessageFromHostData * hostData)135 void Manager::handleMessageFromHost(uint32_t senderInstanceId,
136                                     const chreMessageFromHostData *hostData) {
137   bool success = false;
138   uint32_t messageType = hostData->messageType;
139   if (senderInstanceId != CHRE_INSTANCE_ID) {
140     LOGE("Incorrect sender instance id: %" PRIu32, senderInstanceId);
141   } else if (messageType !=
142              chre_audio_concurrency_test_MessageType_TEST_COMMAND) {
143     LOGE("Invalid message type %" PRIu32, messageType);
144   } else {
145     pb_istream_t istream = pb_istream_from_buffer(
146         static_cast<const pb_byte_t *>(hostData->message),
147         hostData->messageSize);
148     chre_audio_concurrency_test_TestCommand testCommand =
149         chre_audio_concurrency_test_TestCommand_init_default;
150 
151     TestStep step;
152     if (!pb_decode(&istream, chre_audio_concurrency_test_TestCommand_fields,
153                    &testCommand)) {
154       LOGE("Failed to decode start command error %s", PB_GET_ERROR(&istream));
155     } else if (getTestStep(testCommand, &step)) {
156       success = handleTestCommandMessage(hostData->hostEndpoint, step);
157     }
158   }
159 
160   if (!success) {
161     sendTestResultToHost(hostData->hostEndpoint, kTestResultMessageType,
162                          false /* success */);
163   }
164 }
165 
handleDataFromChre(uint16_t eventType,const void * eventData)166 void Manager::handleDataFromChre(uint16_t eventType, const void *eventData) {
167   switch (eventType) {
168     case CHRE_EVENT_AUDIO_DATA:
169       handleAudioDataEvent(static_cast<const chreAudioDataEvent *>(eventData));
170       break;
171 
172     case CHRE_EVENT_TIMER:
173       handleTimer();
174       break;
175 
176     case CHRE_EVENT_AUDIO_SAMPLING_CHANGE:
177       handleAudioSourceStatusEvent(
178           static_cast<const chreAudioSourceStatusEvent *>(eventData));
179       break;
180 
181     default:
182       LOGE("Unexpected event type %" PRIu16, eventType);
183   }
184 }
185 
handleTimer()186 void Manager::handleTimer() {
187   if (mTimerHandle != CHRE_TIMER_INVALID && mTestSession.has_value()) {
188     LOGE("Timed out during test: step %" PRIu8,
189          static_cast<uint8_t>(mTestSession->step));
190     sendTestResultToHost(mTestSession->hostEndpointId, kTestResultMessageType,
191                          false /* success */);
192     mTestSession.reset();
193   }
194 }
195 
setTimeoutTimer(uint32_t durationSeconds)196 bool Manager::setTimeoutTimer(uint32_t durationSeconds) {
197   mTimerHandle = chreTimerSet(durationSeconds * kOneSecondInNanoseconds,
198                               nullptr /* cookie */, true /* oneShot */);
199   if (mTimerHandle == CHRE_TIMER_INVALID) {
200     LOGE("Failed to set timeout timer");
201   }
202 
203   return mTimerHandle != CHRE_TIMER_INVALID;
204 }
205 
cancelTimeoutTimer()206 void Manager::cancelTimeoutTimer() {
207   if (mTimerHandle != CHRE_TIMER_INVALID) {
208     chreTimerCancel(mTimerHandle);
209     mTimerHandle = CHRE_TIMER_INVALID;
210   }
211 }
212 
validateAudioDataEvent(const chreAudioDataEvent * data)213 bool Manager::validateAudioDataEvent(const chreAudioDataEvent *data) {
214   bool success = false;
215   if (data == nullptr) {
216     LOGE("data is nullptr");
217   } else if (data->format == CHRE_AUDIO_DATA_FORMAT_8_BIT_U_LAW) {
218     if (data->samplesULaw8 == nullptr) {
219       LOGE("samplesULaw8 is nullptr");
220     }
221   } else if (data->format != CHRE_AUDIO_DATA_FORMAT_16_BIT_SIGNED_PCM) {
222     LOGE("Invalid format %" PRIu8, data->format);
223   } else if (data->samplesS16 == nullptr) {
224     LOGE("samplesS16 is nullptr");
225   } else if (data->sampleCount == 0) {
226     LOGE("The sample count is 0");
227   } else if (data->sampleCount <
228              static_cast<uint64_t>(mAudioSource.minBufferDuration *
229                                    static_cast<double>(data->sampleRate) /
230                                    kOneSecondInNanoseconds)) {
231     LOGE("The sample count is less than the minimum number of samples");
232   } else if (!checkAudioSamplesAllZeros(data->samplesS16, data->sampleCount)) {
233     LOGE("Audio samples are all zero");
234   } else if (!checkAudioSamplesAllSame(data->samplesS16, data->sampleCount)) {
235     LOGE("Audio samples are all the same");
236   } else {
237     // Verify that timestamp increases.
238     static uint64_t lastTimestamp = 0;
239     bool timestampValid = data->timestamp > lastTimestamp;
240     lastTimestamp = data->timestamp;
241 
242     // Verify the gap was properly announced.
243     bool gapValidationValid = true;
244     double sampleTimeInNs =
245         kOneSecondInNanoseconds / static_cast<double>(data->sampleRate);
246     if (mLastAudioBufferEndTimestampNs.has_value() &&
247         data->timestamp > *mLastAudioBufferEndTimestampNs) {
248       uint64_t gapNs = data->timestamp - *mLastAudioBufferEndTimestampNs;
249       if (gapNs > kMaxMissedSamples * sampleTimeInNs &&
250           !mSawSuspendAudioEvent) {
251         LOGE(
252             "Audio was suspended, but we did not receive a "
253             "CHRE_EVENT_AUDIO_SAMPLING_CHANGE event.");
254         LOGE("gap = %" PRIu64 " ns", gapNs);
255         gapValidationValid = false;
256       }
257     }
258 
259     // Record last audio timestamp at end of buffer
260     mLastAudioBufferEndTimestampNs =
261         data->timestamp + data->sampleCount * sampleTimeInNs;
262 
263     success = timestampValid && (!mVerifyAudioGaps || gapValidationValid);
264   }
265 
266   return success;
267 }
268 
handleAudioDataEvent(const chreAudioDataEvent * data)269 void Manager::handleAudioDataEvent(const chreAudioDataEvent *data) {
270   if (!mTestSession.has_value()) {
271     return;
272   }
273 
274   if (!validateAudioDataEvent(data)) {
275     sendTestResultToHost(mTestSession->hostEndpointId, kTestResultMessageType,
276                          false /* success */);
277     mTestSession.reset();
278     return;
279   }
280 
281   switch (mTestSession->step) {
282     case TestStep::ENABLE_AUDIO_WITH_GAP_VERIFICATION:
283     case TestStep::ENABLE_AUDIO: {
284       cancelTimeoutTimer();
285       sendEmptyMessageToHost(
286           mTestSession->hostEndpointId,
287           chre_audio_concurrency_test_MessageType_TEST_AUDIO_ENABLED);
288 
289       // Reset the test session to avoid sending multiple TEST_AUDIO_ENABLED
290       // messages to the host, while we wait for the next step.
291       mTestSession.reset();
292       break;
293     }
294 
295     case TestStep::VERIFY_AUDIO_RESUME: {
296       cancelTimeoutTimer();
297       sendTestResultToHost(mTestSession->hostEndpointId, kTestResultMessageType,
298                            true /* success */);
299       mTestSession.reset();
300       break;
301     }
302 
303     default:
304       LOGE("Unexpected test step %" PRIu8,
305            static_cast<uint8_t>(mTestSession->step));
306       break;
307   }
308 }
309 
handleAudioSourceStatusEvent(const chreAudioSourceStatusEvent * data)310 void Manager::handleAudioSourceStatusEvent(
311     const chreAudioSourceStatusEvent *data) {
312   if (data != nullptr) {
313     LOGI("Audio source status event received");
314     LOGI("Event: handle: %" PRIu32 ", enabled: %s, suspended: %s", data->handle,
315          data->status.enabled ? "true" : "false",
316          data->status.suspended ? "true" : "false");
317 
318     if (mTestSession.has_value() &&
319         (mTestSession->step == TestStep::ENABLE_AUDIO ||
320          mTestSession->step == TestStep::ENABLE_AUDIO_WITH_GAP_VERIFICATION ||
321          mTestSession->step == TestStep::VERIFY_AUDIO_RESUME) &&
322         data->handle == kAudioHandle && data->status.suspended) {
323       mSawSuspendAudioEvent = true;
324     }
325   } else if (mTestSession.has_value()) {
326     LOGE("Invalid data (data == nullptr)");
327     sendTestResultToHost(mTestSession->hostEndpointId, kTestResultMessageType,
328                          false /* success */);
329     mTestSession.reset();
330   }
331 }
332 
handleEvent(uint32_t senderInstanceId,uint16_t eventType,const void * eventData)333 void Manager::handleEvent(uint32_t senderInstanceId, uint16_t eventType,
334                           const void *eventData) {
335   if (eventType == CHRE_EVENT_MESSAGE_FROM_HOST) {
336     handleMessageFromHost(
337         senderInstanceId,
338         static_cast<const chreMessageFromHostData *>(eventData));
339   } else if (senderInstanceId == CHRE_INSTANCE_ID) {
340     handleDataFromChre(eventType, eventData);
341   } else {
342     LOGW("Got unknown event type from senderInstanceId %" PRIu32
343          " and with eventType %" PRIu16,
344          senderInstanceId, eventType);
345   }
346 }
347 
348 }  // namespace audio_concurrency_test
349 
350 }  // namespace chre
351