1 /*
2  * Copyright (C) 2022 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 "event_logger.h"
18 
19 #include <inttypes.h>
20 #include <stdio.h>
21 #include <chrono>
22 #include <cstddef>
23 #include <ctime>
24 #include <string>
25 
26 namespace aidl::android::hardware::contexthub {
27 
28 namespace {
29 
30 /**
31  * Returns the time formatted in the local timezone.
32  * The format is similar to the adb logcat format, i.e. `01-31 18:22:51.275`.
33  */
formatLocalTime(int64_t ms)34 std::string formatLocalTime(int64_t ms) {
35   const std::chrono::milliseconds duration(ms);
36   const std::chrono::time_point<std::chrono::system_clock> timePoint(duration);
37   time_t time = std::chrono::system_clock::to_time_t(timePoint);
38   constexpr int kBufferSize = 50;
39   char buffer[kBufferSize];
40   std::strftime(buffer, kBufferSize, "%m-%d %H:%M:%S.", std::localtime(&time));
41   return std::string(buffer) + std::to_string(1000 + ms % 1000).substr(1);
42 }
43 
44 }  // namespace
45 
logNanoappLoad(uint64_t appId,size_t appSize,uint32_t appVersion,bool success)46 void EventLogger::logNanoappLoad(uint64_t appId, size_t appSize,
47                                  uint32_t appVersion, bool success) {
48   std::lock_guard<std::mutex> lock(mQueuesMutex);
49   mNanoappLoads.kick_push({
50       .timestampMs = getTimeMs(),
51       .id = static_cast<int64_t>(appId),
52       .version = static_cast<int32_t>(appVersion),
53       .sizeBytes = appSize,
54       .success = success,
55   });
56 }
57 
logNanoappUnload(int64_t appId,bool success)58 void EventLogger::logNanoappUnload(int64_t appId, bool success) {
59   std::lock_guard<std::mutex> lock(mQueuesMutex);
60   mNanoappUnloads.kick_push({
61       .timestampMs = getTimeMs(),
62       .id = appId,
63       .success = success,
64   });
65 }
66 
logContextHubRestart()67 void EventLogger::logContextHubRestart() {
68   std::lock_guard<std::mutex> lock(mQueuesMutex);
69   mContextHubRestarts.kick_push(getTimeMs());
70 }
71 
logMessageToNanoapp(const ContextHubMessage & message,bool success)72 void EventLogger::logMessageToNanoapp(const ContextHubMessage &message,
73                                       bool success) {
74   std::lock_guard<std::mutex> lock(mQueuesMutex);
75   mMsgToNanoapp.kick_push({
76       .timestampMs = getTimeMs(),
77       .id = message.nanoappId,
78       .sizeBytes = message.messageBody.size(),
79       .success = success,
80   });
81 }
82 
logMessageFromNanoapp(const::chre::fbs::NanoappMessageT & message)83 void EventLogger::logMessageFromNanoapp(
84     const ::chre::fbs::NanoappMessageT &message) {
85   std::lock_guard<std::mutex> lock(mQueuesMutex);
86   mMsgFromNanoapp.kick_push({
87       .timestampMs = getTimeMs(),
88       .id = static_cast<int64_t>(message.app_id),
89       .sizeBytes = message.message.size(),
90   });
91 }
92 
logMessageFromNanoapp(const ContextHubMessage & message)93 void EventLogger::logMessageFromNanoapp(const ContextHubMessage &message) {
94   std::lock_guard<std::mutex> lock(mQueuesMutex);
95   mMsgFromNanoapp.kick_push({
96       .timestampMs = getTimeMs(),
97       .id = message.nanoappId,
98       .sizeBytes = message.messageBody.size(),
99   });
100 }
101 
dump() const102 std::string EventLogger::dump() const {
103   constexpr int kBufferSize = 100;
104   char buffer[kBufferSize];
105   std::string logs;
106   std::lock_guard<std::mutex> lock(mQueuesMutex);
107 
108   logs.append("\nNanoapp loads:\n");
109   for (const NanoappLoad &load : mNanoappLoads) {
110     // Use snprintf because std::format is not available and fmtlib {:x} format
111     // crashes.
112     if (snprintf(buffer, kBufferSize,
113                  "  %s id 0x%" PRIx64 " version 0x%" PRIx32 " size %zu"
114                  " status %s\n",
115                  formatLocalTime(load.timestampMs).c_str(), load.id,
116                  load.version, load.sizeBytes,
117                  load.success ? "ok" : "fail") > 0) {
118       logs.append(buffer);
119     }
120   }
121 
122   logs.append("\nNanoapp unloads:\n");
123   for (const NanoappUnload &unload : mNanoappUnloads) {
124     if (snprintf(buffer, kBufferSize, "  %s id 0x%" PRIx64 " status %s\n",
125                  formatLocalTime(unload.timestampMs).c_str(), unload.id,
126                  unload.success ? "ok" : "fail") > 0) {
127       logs.append(buffer);
128     }
129   }
130 
131   logs.append("\nMessages to Nanoapps:\n");
132   for (const NanoappMessage &msg : mMsgToNanoapp) {
133     if (snprintf(buffer, kBufferSize,
134                  "  %s to id 0x%" PRIx64 " size %zu status %s\n",
135                  formatLocalTime(msg.timestampMs).c_str(), msg.id,
136                  msg.sizeBytes, msg.success ? "ok" : "fail") > 0) {
137       logs.append(buffer);
138     }
139   }
140 
141   logs.append("\nMessages from Nanoapps:\n");
142   for (const NanoappMessage &msg : mMsgFromNanoapp) {
143     if (snprintf(buffer, kBufferSize, "  %s from id 0x%" PRIx64 " size %zu\n",
144                  formatLocalTime(msg.timestampMs).c_str(), msg.id,
145                  msg.sizeBytes) > 0) {
146       logs.append(buffer);
147     }
148   }
149 
150   logs.append("\nContext hub restarts:\n");
151   for (const int64_t &ms : mContextHubRestarts) {
152     if (snprintf(buffer, kBufferSize, "  %s\n", formatLocalTime(ms).c_str()) >
153         0) {
154       logs.append(buffer);
155     }
156   }
157 
158   return logs;
159 }
160 
getTimeMs() const161 int64_t EventLogger::getTimeMs() const {
162   if (mNowMs.has_value()) {
163     return mNowMs.value();
164   }
165   struct timespec now;
166   clock_gettime(CLOCK_REALTIME, &now);
167   return 1000 * now.tv_sec + static_cast<int64_t>(now.tv_nsec / 1e6);
168 }
169 
170 }  // namespace aidl::android::hardware::contexthub