1 /*
2  * Copyright (C) 2017 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 "host/commands/kernel_log_monitor/kernel_log_server.h"
18 
19 #include <string>
20 #include <tuple>
21 #include <utility>
22 
23 #include <android-base/logging.h>
24 #include <android-base/strings.h>
25 #include <netinet/in.h>
26 #include "common/libs/fs/shared_select.h"
27 #include "host/libs/config/cuttlefish_config.h"
28 
29 namespace {
30 
31 using cuttlefish::SharedFD;
32 using monitor::Event;
33 
34 constexpr struct {
35   std::string_view match;   // Substring to match in the kernel logs
36   std::string_view prefix;  // Prefix value to output, describing the entry
37 } kInformationalPatterns[] = {
38     {"U-Boot ", "GUEST_UBOOT_VERSION: "},
39     {"] Linux version ", "GUEST_KERNEL_VERSION: "},
40     {"GUEST_BUILD_FINGERPRINT: ", "GUEST_BUILD_FINGERPRINT: "},
41 };
42 
43 enum EventFormat {
44   kBare,          // Just an event, no extra data
45   kKeyValuePair,  // <stage> <key>=<value>
46   kPrefix,        // <stage> <more data>
47 };
48 
49 constexpr struct {
50   std::string_view stage;  // substring in the log identifying the stage
51   Event event;             // emitted when the stage is encountered
52   EventFormat format;      // how the log message is formatted
53 } kStageTable[] = {
54     {cuttlefish::kBootStartedMessage, Event::BootStarted, kBare},
55     {cuttlefish::kBootPendingMessage, Event::BootPending, kPrefix},
56     {cuttlefish::kBootCompletedMessage, Event::BootCompleted, kBare},
57     {cuttlefish::kBootFailedMessage, Event::BootFailed, kPrefix},
58     {cuttlefish::kMobileNetworkConnectedMessage, Event::MobileNetworkConnected,
59      kBare},
60     {cuttlefish::kWifiConnectedMessage, Event::WifiNetworkConnected, kBare},
61     {cuttlefish::kEthernetConnectedMessage, Event::EthernetNetworkConnected,
62      kBare},
63     {cuttlefish::kAdbdStartedMessage, Event::AdbdStarted, kBare},
64     {cuttlefish::kFastbootdStartedMessage, Event::FastbootStarted, kBare},
65     {cuttlefish::kFastbootStartedMessage, Event::FastbootStarted, kBare},
66     {cuttlefish::kScreenChangedMessage, Event::ScreenChanged, kKeyValuePair},
67     {cuttlefish::kBootloaderLoadedMessage, Event::BootloaderLoaded, kBare},
68     {cuttlefish::kKernelLoadedMessage, Event::KernelLoaded, kBare},
69     {cuttlefish::kDisplayPowerModeChangedMessage,
70      monitor::Event::DisplayPowerModeChanged, kKeyValuePair},
71 };
72 
ProcessSubscriptions(Json::Value message,std::vector<monitor::EventCallback> * subscribers)73 void ProcessSubscriptions(
74     Json::Value message,
75     std::vector<monitor::EventCallback>* subscribers) {
76   auto active_subscription_count = subscribers->size();
77   std::size_t idx = 0;
78   while (idx < active_subscription_count) {
79     // Call the callback
80     auto action = (*subscribers)[idx](message);
81     if (action == monitor::SubscriptionAction::ContinueSubscription) {
82       ++idx;
83     } else {
84       // Cancel the subscription by swapping it with the last active subscription
85       // and decreasing the active subscription count
86       --active_subscription_count;
87       std::swap((*subscribers)[idx], (*subscribers)[active_subscription_count]);
88     }
89   }
90   // Keep only the active subscriptions
91   subscribers->resize(active_subscription_count);
92 }
93 }  // namespace
94 
95 namespace monitor {
KernelLogServer(cuttlefish::SharedFD pipe_fd,const std::string & log_name)96 KernelLogServer::KernelLogServer(cuttlefish::SharedFD pipe_fd,
97                                  const std::string& log_name)
98     : pipe_fd_(pipe_fd),
99       log_fd_(cuttlefish::SharedFD::Open(log_name.c_str(),
100                                          O_CREAT | O_RDWR | O_APPEND, 0666)) {}
101 
BeforeSelect(cuttlefish::SharedFDSet * fd_read) const102 void KernelLogServer::BeforeSelect(cuttlefish::SharedFDSet* fd_read) const {
103   fd_read->Set(pipe_fd_);
104 }
105 
AfterSelect(const cuttlefish::SharedFDSet & fd_read)106 void KernelLogServer::AfterSelect(const cuttlefish::SharedFDSet& fd_read) {
107   if (fd_read.IsSet(pipe_fd_)) {
108     HandleIncomingMessage();
109   }
110 }
111 
SubscribeToEvents(monitor::EventCallback callback)112 void KernelLogServer::SubscribeToEvents(monitor::EventCallback callback) {
113   subscribers_.push_back(callback);
114 }
115 
HandleIncomingMessage()116 bool KernelLogServer::HandleIncomingMessage() {
117   const size_t buf_len = 256;
118   char buf[buf_len];
119   ssize_t ret = pipe_fd_->Read(buf, buf_len);
120   if (ret < 0) {
121     LOG(ERROR) << "Could not read kernel logs: " << pipe_fd_->StrError();
122     return false;
123   }
124   if (ret == 0) {
125     return false;
126   }
127   // Write the log to a file
128   if (log_fd_->Write(buf, ret) < 0) {
129     LOG(ERROR) << "Could not write kernel log to file: " << log_fd_->StrError();
130     return false;
131   }
132 
133   // Detect VIRTUAL_DEVICE_BOOT_*
134   for (ssize_t i=0; i<ret; i++) {
135     if ('\n' == buf[i]) {
136       for (auto& [match, prefix] : kInformationalPatterns) {
137         auto pos = line_.find(match);
138         if (std::string::npos != pos) {
139           LOG(INFO) << prefix << line_.substr(pos + match.size());
140         }
141       }
142       for (const auto& [stage, event, format] : kStageTable) {
143         auto pos = line_.find(stage);
144         if (std::string::npos != pos) {
145           // Log the stage
146           if (format == kPrefix) {
147             LOG(INFO) << line_.substr(pos);
148           } else {
149             LOG(INFO) << stage;
150           }
151 
152           Json::Value message;
153           message["event"] = event;
154           Json::Value metadata;
155 
156           if (format == kKeyValuePair) {
157             // Expect space-separated key=value pairs in the log message.
158             const auto& fields =
159                 android::base::Split(line_.substr(pos + stage.size()), " ");
160             for (std::string field : fields) {
161               field = android::base::Trim(field);
162               if (field.empty()) {
163                 // Expected; android::base::Split() always returns at least
164                 // one (possibly empty) string.
165                 LOG(DEBUG) << "Empty field for line: " << line_;
166                 continue;
167               }
168               const auto& keyvalue = android::base::Split(field, "=");
169               if (keyvalue.size() != 2) {
170                 LOG(WARNING) << "Field is not in key=value format: " << field;
171                 continue;
172               }
173               metadata[keyvalue[0]] = keyvalue[1];
174             }
175           }
176           message["metadata"] = metadata;
177           ProcessSubscriptions(message, &subscribers_);
178         }
179       }
180       line_.clear();
181     }
182     line_.append(1, buf[i]);
183   }
184 
185   return true;
186 }
187 
188 }  // namespace monitor
189