1 /*
2 * Copyright (C) 2021 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 // TODO(b/298459533): remove_ap_wakeup_metric_report_limit ramp up -> remove old
18 // code
19
20 #define LOG_TAG "ContextHubHal"
21 #define LOG_NDEBUG 1
22
23 #include "hal_chre_socket_connection.h"
24
25 #include <log/log.h>
26
27 #ifdef CHRE_HAL_SOCKET_METRICS_ENABLED
28 // TODO(b/298459533): Remove these when the flag_log_nanoapp_load_metrics flag
29 // is cleaned up
30 #include <aidl/android/frameworks/stats/IStats.h>
31 #include <android/binder_manager.h>
32 #include <android_chre_flags.h>
33 // TODO(b/298459533): Remove end
34
35 #include <chre_atoms_log.h>
36 #include <utils/SystemClock.h>
37 #endif // CHRE_HAL_SOCKET_METRICS_ENABLED
38
39 namespace android {
40 namespace hardware {
41 namespace contexthub {
42 namespace common {
43 namespace implementation {
44
45 using ::android::chre::FragmentedLoadRequest;
46 using ::android::chre::FragmentedLoadTransaction;
47 using ::android::chre::HostProtocolHost;
48 using ::flatbuffers::FlatBufferBuilder;
49
50 #ifdef CHRE_HAL_SOCKET_METRICS_ENABLED
51 // TODO(b/298459533): Remove these when the flag_log_nanoapp_load_metrics flag
52 // is cleaned up
53 using ::aidl::android::frameworks::stats::IStats;
54 using ::aidl::android::frameworks::stats::VendorAtom;
55 using ::aidl::android::frameworks::stats::VendorAtomValue;
56 using ::android::chre::Atoms::CHRE_AP_WAKE_UP_OCCURRED;
57 using ::android::chre::Atoms::CHRE_HAL_NANOAPP_LOAD_FAILED;
58 using ::android::chre::flags::flag_log_nanoapp_load_metrics;
59 using ::android::chre::flags::remove_ap_wakeup_metric_report_limit;
60 // TODO(b/298459533): Remove end
61
62 using ::android::chre::MetricsReporter;
63 using ::android::chre::Atoms::ChreHalNanoappLoadFailed;
64 #endif // CHRE_HAL_SOCKET_METRICS_ENABLED
65
HalChreSocketConnection(IChreSocketCallback * callback)66 HalChreSocketConnection::HalChreSocketConnection(
67 IChreSocketCallback *callback) {
68 constexpr char kChreSocketName[] = "chre";
69
70 mSocketCallbacks = sp<SocketCallbacks>::make(*this, callback);
71 if (!mClient.connectInBackground(kChreSocketName, mSocketCallbacks)) {
72 ALOGE("Couldn't start socket client");
73 }
74 }
75
getContextHubs(::chre::fbs::HubInfoResponseT * response)76 bool HalChreSocketConnection::getContextHubs(
77 ::chre::fbs::HubInfoResponseT *response) {
78 constexpr auto kHubInfoQueryTimeout = std::chrono::seconds(5);
79 ALOGV("%s", __func__);
80
81 // If we're not connected yet, give it some time
82 // TODO refactor from polling into conditional wait
83 int maxSleepIterations = 250;
84 while (!mHubInfoValid && !mClient.isConnected() && --maxSleepIterations > 0) {
85 std::this_thread::sleep_for(std::chrono::milliseconds(20));
86 }
87
88 if (!mClient.isConnected()) {
89 ALOGE("Couldn't connect to hub daemon");
90 } else if (!mHubInfoValid) {
91 // We haven't cached the hub details yet, so send a request and block
92 // waiting on a response
93 std::unique_lock<std::mutex> lock(mHubInfoMutex);
94 FlatBufferBuilder builder;
95 HostProtocolHost::encodeHubInfoRequest(builder);
96
97 ALOGD("Sending hub info request");
98 if (!mClient.sendMessage(builder.GetBufferPointer(), builder.GetSize())) {
99 ALOGE("Couldn't send hub info request");
100 } else {
101 mHubInfoCond.wait_for(lock, kHubInfoQueryTimeout,
102 [this]() { return mHubInfoValid; });
103 }
104 }
105
106 if (mHubInfoValid) {
107 *response = mHubInfoResponse;
108 } else {
109 ALOGE("Unable to get hub info from CHRE");
110 }
111
112 return mHubInfoValid;
113 }
114
sendDebugConfiguration()115 bool HalChreSocketConnection::sendDebugConfiguration() {
116 FlatBufferBuilder builder;
117 HostProtocolHost::encodeDebugConfiguration(builder);
118 return mClient.sendMessage(builder.GetBufferPointer(), builder.GetSize());
119 }
120
sendMessageToHub(uint64_t nanoappId,uint32_t messageType,uint16_t hostEndpointId,const unsigned char * payload,size_t payloadLength)121 bool HalChreSocketConnection::sendMessageToHub(uint64_t nanoappId,
122 uint32_t messageType,
123 uint16_t hostEndpointId,
124 const unsigned char *payload,
125 size_t payloadLength) {
126 FlatBufferBuilder builder(1024);
127 HostProtocolHost::encodeNanoappMessage(
128 builder, nanoappId, messageType, hostEndpointId, payload, payloadLength);
129 return mClient.sendMessage(builder.GetBufferPointer(), builder.GetSize());
130 }
131
loadNanoapp(FragmentedLoadTransaction & transaction)132 bool HalChreSocketConnection::loadNanoapp(
133 FragmentedLoadTransaction &transaction) {
134 bool success = false;
135 std::lock_guard<std::mutex> lock(mPendingLoadTransactionMutex);
136
137 if (mPendingLoadTransaction.has_value()) {
138 ALOGE("Pending load transaction exists. Overriding pending request");
139 }
140
141 mPendingLoadTransaction = transaction;
142 success = sendFragmentedLoadNanoAppRequest(mPendingLoadTransaction.value());
143 if (!success) {
144 mPendingLoadTransaction.reset();
145 }
146
147 return success;
148 }
149
unloadNanoapp(uint64_t appId,uint32_t transactionId)150 bool HalChreSocketConnection::unloadNanoapp(uint64_t appId,
151 uint32_t transactionId) {
152 FlatBufferBuilder builder(64);
153 HostProtocolHost::encodeUnloadNanoappRequest(
154 builder, transactionId, appId, false /* allowSystemNanoappUnload */);
155 return mClient.sendMessage(builder.GetBufferPointer(), builder.GetSize());
156 }
157
queryNanoapps()158 bool HalChreSocketConnection::queryNanoapps() {
159 FlatBufferBuilder builder(64);
160 HostProtocolHost::encodeNanoappListRequest(builder);
161 return mClient.sendMessage(builder.GetBufferPointer(), builder.GetSize());
162 }
163
requestDebugDump()164 bool HalChreSocketConnection::requestDebugDump() {
165 FlatBufferBuilder builder;
166 HostProtocolHost::encodeDebugDumpRequest(builder);
167 return mClient.sendMessage(builder.GetBufferPointer(), builder.GetSize());
168 }
169
sendSettingChangedNotification(::chre::fbs::Setting fbsSetting,::chre::fbs::SettingState fbsState)170 bool HalChreSocketConnection::sendSettingChangedNotification(
171 ::chre::fbs::Setting fbsSetting, ::chre::fbs::SettingState fbsState) {
172 FlatBufferBuilder builder(64);
173 HostProtocolHost::encodeSettingChangeNotification(builder, fbsSetting,
174 fbsState);
175 return mClient.sendMessage(builder.GetBufferPointer(), builder.GetSize());
176 }
177
onHostEndpointConnected(uint16_t hostEndpointId,uint8_t type,const std::string & package_name,const std::string & attribution_tag)178 bool HalChreSocketConnection::onHostEndpointConnected(
179 uint16_t hostEndpointId, uint8_t type, const std::string &package_name,
180 const std::string &attribution_tag) {
181 FlatBufferBuilder builder(64);
182 HostProtocolHost::encodeHostEndpointConnected(builder, hostEndpointId, type,
183 package_name, attribution_tag);
184 return mClient.sendMessage(builder.GetBufferPointer(), builder.GetSize());
185 }
186
onHostEndpointDisconnected(uint16_t hostEndpointId)187 bool HalChreSocketConnection::onHostEndpointDisconnected(
188 uint16_t hostEndpointId) {
189 FlatBufferBuilder builder(64);
190 HostProtocolHost::encodeHostEndpointDisconnected(builder, hostEndpointId);
191 return mClient.sendMessage(builder.GetBufferPointer(), builder.GetSize());
192 }
193
isLoadTransactionPending()194 bool HalChreSocketConnection::isLoadTransactionPending() {
195 std::lock_guard<std::mutex> lock(mPendingLoadTransactionMutex);
196 return mPendingLoadTransaction.has_value();
197 }
198
SocketCallbacks(HalChreSocketConnection & parent,IChreSocketCallback * callback)199 HalChreSocketConnection::SocketCallbacks::SocketCallbacks(
200 HalChreSocketConnection &parent, IChreSocketCallback *callback)
201 : mParent(parent), mCallback(callback) {
202 #ifdef CHRE_HAL_SOCKET_METRICS_ENABLED
203 if (!remove_ap_wakeup_metric_report_limit()) {
204 mLastClearedTimestamp = elapsedRealtime();
205 }
206 #endif // CHRE_HAL_SOCKET_METRICS_ENABLED
207 }
208
onMessageReceived(const void * data,size_t length)209 void HalChreSocketConnection::SocketCallbacks::onMessageReceived(
210 const void *data, size_t length) {
211 if (!HostProtocolHost::decodeMessageFromChre(data, length, *this)) {
212 ALOGE("Failed to decode message");
213 }
214 }
215
onConnected()216 void HalChreSocketConnection::SocketCallbacks::onConnected() {
217 ALOGI("Reconnected to CHRE daemon");
218 if (mHaveConnected) {
219 ALOGI("Reconnected to CHRE daemon");
220 mCallback->onContextHubRestarted();
221 }
222 mParent.sendDebugConfiguration();
223 mHaveConnected = true;
224 }
225
onDisconnected()226 void HalChreSocketConnection::SocketCallbacks::onDisconnected() {
227 ALOGW("Lost connection to CHRE daemon");
228 }
229
handleNanoappMessage(const::chre::fbs::NanoappMessageT & message)230 void HalChreSocketConnection::SocketCallbacks::handleNanoappMessage(
231 const ::chre::fbs::NanoappMessageT &message) {
232 ALOGD("Got message from nanoapp: ID 0x%" PRIx64, message.app_id);
233 mCallback->onNanoappMessage(message);
234
235 #ifdef CHRE_HAL_SOCKET_METRICS_ENABLED
236 if (message.woke_host) {
237 // check and update the 24hour timer
238 std::lock_guard<std::mutex> lock(mNanoappWokeApCountMutex);
239 long nanoappId = message.app_id;
240
241 if (!remove_ap_wakeup_metric_report_limit()) {
242 long timeElapsed = elapsedRealtime() - mLastClearedTimestamp;
243 if (timeElapsed > kOneDayinMillis) {
244 mNanoappWokeUpCount = 0;
245 mLastClearedTimestamp = elapsedRealtime();
246 }
247
248 mNanoappWokeUpCount++;
249 }
250
251 if (remove_ap_wakeup_metric_report_limit() ||
252 mNanoappWokeUpCount < kMaxDailyReportedApWakeUp) {
253 if (flag_log_nanoapp_load_metrics()) {
254 if (!mParent.mMetricsReporter.logApWakeupOccurred(nanoappId)) {
255 ALOGE("Could not log AP Wakeup metric");
256 }
257 } else {
258 // create and report the vendor atom
259 std::vector<VendorAtomValue> values(1);
260 values[0].set<VendorAtomValue::longValue>(nanoappId);
261
262 const VendorAtom atom{
263 .atomId = CHRE_AP_WAKE_UP_OCCURRED,
264 .values{std::move(values)},
265 };
266
267 mParent.reportMetric(atom);
268 }
269 }
270 }
271 #endif // CHRE_HAL_SOCKET_METRICS_ENABLED
272 }
273
handleHubInfoResponse(const::chre::fbs::HubInfoResponseT & response)274 void HalChreSocketConnection::SocketCallbacks::handleHubInfoResponse(
275 const ::chre::fbs::HubInfoResponseT &response) {
276 ALOGD("Got hub info response");
277
278 std::lock_guard<std::mutex> lock(mParent.mHubInfoMutex);
279 if (mParent.mHubInfoValid) {
280 ALOGI("Ignoring duplicate/unsolicited hub info response");
281 } else {
282 mParent.mHubInfoResponse = response;
283 mParent.mHubInfoValid = true;
284 mParent.mHubInfoCond.notify_all();
285 }
286 }
287
handleNanoappListResponse(const::chre::fbs::NanoappListResponseT & response)288 void HalChreSocketConnection::SocketCallbacks::handleNanoappListResponse(
289 const ::chre::fbs::NanoappListResponseT &response) {
290 ALOGD("Got nanoapp list response with %zu apps", response.nanoapps.size());
291 mCallback->onNanoappListResponse(response);
292 }
293
handleLoadNanoappResponse(const::chre::fbs::LoadNanoappResponseT & response)294 void HalChreSocketConnection::SocketCallbacks::handleLoadNanoappResponse(
295 const ::chre::fbs::LoadNanoappResponseT &response) {
296 ALOGD("Got load nanoapp response for transaction %" PRIu32
297 " fragment %" PRIu32 " with result %d",
298 response.transaction_id, response.fragment_id, response.success);
299 std::unique_lock<std::mutex> lock(mParent.mPendingLoadTransactionMutex);
300
301 // TODO: Handle timeout in receiving load response
302 if (!mParent.mPendingLoadTransaction.has_value()) {
303 ALOGE(
304 "Dropping unexpected load response (no pending transaction "
305 "exists)");
306 } else {
307 FragmentedLoadTransaction &transaction =
308 mParent.mPendingLoadTransaction.value();
309
310 if (!mParent.isExpectedLoadResponseLocked(response)) {
311 ALOGE("Dropping unexpected load response, expected transaction %" PRIu32
312 " fragment %" PRIu32 ", received transaction %" PRIu32
313 " fragment %" PRIu32,
314 transaction.getTransactionId(), mParent.mCurrentFragmentId,
315 response.transaction_id, response.fragment_id);
316 } else {
317 bool success = false;
318 bool continueLoadRequest = false;
319 if (response.success && !transaction.isComplete()) {
320 if (mParent.sendFragmentedLoadNanoAppRequest(transaction)) {
321 continueLoadRequest = true;
322 success = true;
323 }
324 } else {
325 success = response.success;
326
327 #ifdef CHRE_HAL_SOCKET_METRICS_ENABLED
328 if (!success) {
329 if (flag_log_nanoapp_load_metrics()) {
330 if (!mParent.mMetricsReporter.logNanoappLoadFailed(
331 transaction.getNanoappId(),
332 ChreHalNanoappLoadFailed::TYPE_DYNAMIC,
333 ChreHalNanoappLoadFailed::REASON_ERROR_GENERIC)) {
334 ALOGE("Could not log the nanoapp load failed metric");
335 }
336 }
337 }
338 #endif // CHRE_HAL_SOCKET_METRICS_ENABLED
339 }
340
341 if (!continueLoadRequest) {
342 mParent.mPendingLoadTransaction.reset();
343 lock.unlock();
344 mCallback->onTransactionResult(response.transaction_id, success);
345 }
346 }
347 }
348 }
349
handleUnloadNanoappResponse(const::chre::fbs::UnloadNanoappResponseT & response)350 void HalChreSocketConnection::SocketCallbacks::handleUnloadNanoappResponse(
351 const ::chre::fbs::UnloadNanoappResponseT &response) {
352 ALOGV("Got unload nanoapp response for transaction %" PRIu32
353 " with result %d",
354 response.transaction_id, response.success);
355 mCallback->onTransactionResult(response.transaction_id, response.success);
356 }
357
handleDebugDumpData(const::chre::fbs::DebugDumpDataT & data)358 void HalChreSocketConnection::SocketCallbacks::handleDebugDumpData(
359 const ::chre::fbs::DebugDumpDataT &data) {
360 ALOGV("Got debug dump data, size %zu", data.debug_str.size());
361 mCallback->onDebugDumpData(data);
362 }
363
handleDebugDumpResponse(const::chre::fbs::DebugDumpResponseT & response)364 void HalChreSocketConnection::SocketCallbacks::handleDebugDumpResponse(
365 const ::chre::fbs::DebugDumpResponseT &response) {
366 ALOGV("Got debug dump response, success %d, data count %" PRIu32,
367 response.success, response.data_count);
368 mCallback->onDebugDumpComplete(response);
369 }
370
isExpectedLoadResponseLocked(const::chre::fbs::LoadNanoappResponseT & response)371 bool HalChreSocketConnection::isExpectedLoadResponseLocked(
372 const ::chre::fbs::LoadNanoappResponseT &response) {
373 return mPendingLoadTransaction.has_value() &&
374 (mPendingLoadTransaction->getTransactionId() ==
375 response.transaction_id) &&
376 (response.fragment_id == 0 ||
377 mCurrentFragmentId == response.fragment_id);
378 }
379
sendFragmentedLoadNanoAppRequest(FragmentedLoadTransaction & transaction)380 bool HalChreSocketConnection::sendFragmentedLoadNanoAppRequest(
381 FragmentedLoadTransaction &transaction) {
382 bool success = false;
383 const FragmentedLoadRequest &request = transaction.getNextRequest();
384
385 FlatBufferBuilder builder(128 + request.binary.size());
386 HostProtocolHost::encodeFragmentedLoadNanoappRequest(builder, request);
387
388 if (!mClient.sendMessage(builder.GetBufferPointer(), builder.GetSize())) {
389 ALOGE("Failed to send load request message (fragment ID = %zu)",
390 request.fragmentId);
391
392 #ifdef CHRE_HAL_SOCKET_METRICS_ENABLED
393 if (flag_log_nanoapp_load_metrics()) {
394 if (!mMetricsReporter.logNanoappLoadFailed(
395 request.appId, ChreHalNanoappLoadFailed::TYPE_DYNAMIC,
396 ChreHalNanoappLoadFailed::REASON_CONNECTION_ERROR)) {
397 ALOGE("Could not log the nanoapp load failed metric");
398 }
399 } else {
400 // create and report the vendor atom
401 std::vector<VendorAtomValue> values(3);
402 values[0].set<VendorAtomValue::longValue>(request.appId);
403 values[1].set<VendorAtomValue::intValue>(
404 ChreHalNanoappLoadFailed::TYPE_DYNAMIC);
405 values[2].set<VendorAtomValue::intValue>(
406 ChreHalNanoappLoadFailed::REASON_ERROR_GENERIC);
407
408 const VendorAtom atom{
409 .atomId = CHRE_HAL_NANOAPP_LOAD_FAILED,
410 .values{std::move(values)},
411 };
412 reportMetric(atom);
413 }
414 #endif // CHRE_HAL_SOCKET_METRICS_ENABLED
415
416 } else {
417 mCurrentFragmentId = request.fragmentId;
418 success = true;
419 }
420
421 return success;
422 }
423
424 #ifdef CHRE_HAL_SOCKET_METRICS_ENABLED
425 // TODO(b/298459533): Remove this the flag_log_nanoapp_load_metrics flag is
426 // cleaned up
reportMetric(const VendorAtom atom)427 void HalChreSocketConnection::reportMetric(const VendorAtom atom) {
428 const std::string statsServiceName =
429 std::string(IStats::descriptor).append("/default");
430 if (!AServiceManager_isDeclared(statsServiceName.c_str())) {
431 ALOGE("Stats service is not declared.");
432 return;
433 }
434
435 std::shared_ptr<IStats> stats_client = IStats::fromBinder(ndk::SpAIBinder(
436 AServiceManager_waitForService(statsServiceName.c_str())));
437 if (stats_client == nullptr) {
438 ALOGE("Failed to get IStats service");
439 return;
440 }
441
442 const ndk::ScopedAStatus ret = stats_client->reportVendorAtom(atom);
443 if (!ret.isOk()) {
444 ALOGE("Failed to report vendor atom");
445 }
446 }
447 // TODO(b/298459533): Remove end
448 #endif // CHRE_HAL_SOCKET_METRICS_ENABLED
449
450 } // namespace implementation
451 } // namespace common
452 } // namespace contexthub
453 } // namespace hardware
454 } // namespace android
455