1 // Copyright 2018 The Fuchsia Authors. All rights reserved.
2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file.
4 
5 #include <runtests-utils/log-exporter.h>
6 
7 #include <fbl/string.h>
8 #include <fbl/vector.h>
9 #include <fuchsia/logger/c/fidl.h>
10 #include <lib/async-loop/cpp/loop.h>
11 #include <lib/fidl/cpp/message_buffer.h>
12 #include <unittest/unittest.h>
13 
14 #include <utility>
15 
16 namespace runtests {
17 namespace {
18 
19 // This class is the helper class which will encapsulate a LogMessage and then
20 // fill default values for fidl log message object. It also helps in determining
21 // the lenght of fidl message required to encode this msg object.
22 class LogMessage {
23 public:
LogMessage(fbl::String msg,std::initializer_list<fbl::String> tags,uint32_t dropped_logs=0,uint64_t pid=1024)24     LogMessage(fbl::String msg, std::initializer_list<fbl::String> tags,
25                uint32_t dropped_logs = 0, uint64_t pid = 1024)
26         : msg_(msg), tags_(tags), pid_(pid), dropped_logs_(dropped_logs) {}
27 
LogMessage(fbl::String msg,uint32_t dropped_logs=0,uint64_t pid=1024)28     LogMessage(fbl::String msg, uint32_t dropped_logs = 0, uint64_t pid = 1024)
29         : LogMessage(msg, {}, dropped_logs, pid) {}
30 
TagsCount() const31     size_t TagsCount() const {
32         return tags_.size();
33     }
34 
tag(size_t index) const35     const fbl::String* tag(size_t index) const {
36         return &tags_[index];
37     }
38 
msg() const39     const fbl::String* msg() const {
40         return &msg_;
41     }
42 
SetFidlLogMessageValues(fuchsia_logger_LogMessage * lm) const43     void SetFidlLogMessageValues(fuchsia_logger_LogMessage* lm) const {
44         lm->pid = pid_;
45         lm->tid = 1034;
46         lm->time = 93892493921;
47         lm->severity = fuchsia_logger_LogLevelFilter_INFO;
48         lm->dropped_logs = dropped_logs_;
49         lm->tags.count = tags_.size();
50         lm->tags.data = reinterpret_cast<void*>(FIDL_ALLOC_PRESENT);
51         lm->msg.size = msg_.length();
52         lm->msg.data = reinterpret_cast<char*>(FIDL_ALLOC_PRESENT);
53     }
54 
GetFidlStringLen() const55     size_t GetFidlStringLen() const {
56         size_t len = 0;
57         for (size_t i = 0; i < tags_.size(); i++) {
58             len += FIDL_ALIGN(tags_[i].length());
59         }
60         return len + FIDL_ALIGN(msg_.length());
61     }
62 
63 private:
64     fbl::String msg_;
65     fbl::Vector<fbl::String> tags_;
66     uint64_t pid_;
67     uint32_t dropped_logs_;
68 };
69 
70 // Encode |log_msg| and fills up fidl message object to be sent to LogListener
71 // implementation.
FillLogMessagePayload(fuchsia_logger_LogMessage * lm,fidl_string_t * strings,const LogMessage & log_msg)72 size_t FillLogMessagePayload(fuchsia_logger_LogMessage* lm, fidl_string_t* strings,
73                              const LogMessage& log_msg) {
74     log_msg.SetFidlLogMessageValues(lm);
75     uint8_t* payload = reinterpret_cast<uint8_t*>(strings + log_msg.TagsCount());
76     size_t offset = 0;
77 
78     // write tags
79     for (size_t i = 0; i < log_msg.TagsCount(); ++i) {
80         size_t size = log_msg.tag(i)->length();
81         strings[i].size = size;
82         strings[i].data = reinterpret_cast<char*> FIDL_ALLOC_PRESENT;
83         memcpy(payload + offset, log_msg.tag(i)->data(), size);
84         offset += FIDL_ALIGN(size);
85     }
86 
87     // write msg
88     auto msg = log_msg.msg();
89     memcpy(payload + offset, msg->data(), msg->length());
90     offset += FIDL_ALIGN(msg->length());
91     return log_msg.TagsCount() * sizeof(fidl_string_t) + offset;
92 }
93 
94 // Encode |log_msgs| with help from other helpers and writes the msg to
95 // |listener|.
SendLogMessagesHelper(const zx::channel & listener,int oridinal,const fbl::Vector<LogMessage> & log_msgs)96 zx_status_t SendLogMessagesHelper(const zx::channel& listener, int oridinal,
97                                   const fbl::Vector<LogMessage>& log_msgs) {
98     size_t n_msgs = log_msgs.size();
99     if (n_msgs == 0) {
100         return ZX_ERR_INVALID_ARGS;
101     }
102     size_t tags_n_msgs = 0;
103     size_t len = 0;
104     for (size_t i = 0; i < n_msgs; i++) {
105         tags_n_msgs += log_msgs[i].TagsCount();
106         len += log_msgs[i].GetFidlStringLen();
107     }
108 
109     size_t msg_len = sizeof(fidl_message_header_t) + n_msgs * sizeof(fuchsia_logger_LogMessage) +
110                      tags_n_msgs * sizeof(fidl_string_t) + FIDL_ALIGN(len);
111     if (oridinal == fuchsia_logger_LogListenerLogManyOrdinal) {
112         msg_len += sizeof(fidl_vector_t);
113     }
114     if (msg_len > UINT32_MAX) {
115         return ZX_ERR_INVALID_ARGS;
116     }
117     uint8_t msg[msg_len];
118     memset(msg, 0, msg_len);
119     fidl_message_header_t* hdr = reinterpret_cast<fidl_message_header_t*>(msg);
120     hdr->ordinal = oridinal;
121     fuchsia_logger_LogMessage* fidl_log_msg = reinterpret_cast<fuchsia_logger_LogMessage*>(hdr + 1);
122     if (oridinal == fuchsia_logger_LogListenerLogManyOrdinal) {
123         fidl_vector_t* vector = reinterpret_cast<fidl_vector_t*>(hdr + 1);
124         vector->count = n_msgs;
125         vector->data = reinterpret_cast<void*>(FIDL_ALLOC_PRESENT);
126         fidl_log_msg = reinterpret_cast<fuchsia_logger_LogMessage*>(vector + 1);
127     }
128     fidl_string_t* strings = reinterpret_cast<fidl_string_t*>(fidl_log_msg + n_msgs);
129 
130     for (size_t i = 0; i < n_msgs; i++) {
131         size_t offset = FillLogMessagePayload(fidl_log_msg, strings, log_msgs[i]);
132         if (i < n_msgs - 1) {
133             fidl_log_msg++;
134             strings = reinterpret_cast<fidl_string_t*>((reinterpret_cast<uint8_t*>(strings)) + offset);
135         }
136     }
137     return listener.write(0, msg, static_cast<uint32_t>(msg_len), NULL, 0);
138 }
139 
140 // Encodes and writes |log_msg| to |listener|. This will replicate behaviour of
141 // Log call in Log interface.
SendLogMessage(const zx::channel & listener,LogMessage log_msg)142 zx_status_t SendLogMessage(const zx::channel& listener, LogMessage log_msg) {
143     fbl::Vector<LogMessage> log_msgs;
144     log_msgs.push_back(std::move(log_msg));
145     return SendLogMessagesHelper(listener, fuchsia_logger_LogListenerLogOrdinal, log_msgs);
146 }
147 
148 // Encodes and writes |log_msgs| to |listener|. This will replicate behaviour of
149 // LogMany call in Log interface.
SendLogMessages(const zx::channel & listener,const fbl::Vector<LogMessage> & log_msgs)150 zx_status_t SendLogMessages(const zx::channel& listener,
151                             const fbl::Vector<LogMessage>& log_msgs) {
152     return SendLogMessagesHelper(listener, fuchsia_logger_LogListenerLogManyOrdinal, log_msgs);
153 }
154 
TestLog()155 bool TestLog() {
156     BEGIN_TEST;
157     zx::channel listener, listener_request;
158     ASSERT_EQ(ZX_OK, zx::channel::create(0, &listener, &listener_request));
159 
160     // We expect the log file to be much smaller than this.
161     char buf[1024];
162     memset(buf, 0, sizeof(buf));
163     FILE* buf_file = fmemopen(buf, sizeof(buf), "w");
164 
165     // start listener
166     auto log_listener = fbl::make_unique<LogExporter>(std::move(listener_request), buf_file);
167     log_listener->set_error_handler([](zx_status_t status) {
168         EXPECT_EQ(ZX_ERR_CANCELED, status);
169     });
170 
171     LogMessage msg1("my message");
172     ASSERT_EQ(ZX_OK, SendLogMessage(listener, std::move(msg1)));
173     LogMessage msg2("my message", {"tag123"});
174     ASSERT_EQ(ZX_OK, SendLogMessage(listener, std::move(msg2)));
175 
176     ASSERT_EQ(ZX_OK, log_listener->RunUntilIdle());
177     fflush(buf_file);
178 
179     ASSERT_STR_EQ(R"([00093.892493][1024][1034][] INFO: my message
180 [00093.892493][1024][1034][tag123] INFO: my message
181 )",
182                   buf);
183 
184     LogMessage msg3("my message", {"tag123", "tag2"});
185     ASSERT_EQ(ZX_OK, SendLogMessage(listener, std::move(msg3)));
186 
187     ASSERT_EQ(ZX_OK, log_listener->RunUntilIdle());
188     fflush(buf_file);
189 
190     ASSERT_STR_EQ(R"([00093.892493][1024][1034][] INFO: my message
191 [00093.892493][1024][1034][tag123] INFO: my message
192 [00093.892493][1024][1034][tag123, tag2] INFO: my message
193 )",
194                   buf);
195     END_TEST;
196 }
197 
TestLogMany()198 bool TestLogMany() {
199     BEGIN_TEST;
200     zx::channel listener, listener_request;
201     ASSERT_EQ(ZX_OK, zx::channel::create(0, &listener, &listener_request));
202 
203     // We expect the log file to be much smaller than this.
204     char buf[1024];
205     memset(buf, 0, sizeof(buf));
206     FILE* buf_file = fmemopen(buf, sizeof(buf), "w");
207 
208     // start listener
209     auto log_listener = fbl::make_unique<LogExporter>(std::move(listener_request), buf_file);
210     log_listener->set_error_handler([](zx_status_t status) {
211         EXPECT_EQ(ZX_ERR_CANCELED, status);
212     });
213 
214     LogMessage msg1("my message");
215     LogMessage msg2("my message2", {"tag1", "tag2"});
216     fbl::Vector<LogMessage> msgs;
217     msgs.push_back(std::move(msg1));
218     msgs.push_back(std::move(msg2));
219     ASSERT_EQ(ZX_OK, SendLogMessages(listener, msgs));
220 
221     ASSERT_EQ(ZX_OK, log_listener->RunUntilIdle());
222     fflush(buf_file);
223 
224     ASSERT_STR_EQ(R"([00093.892493][1024][1034][] INFO: my message
225 [00093.892493][1024][1034][tag1, tag2] INFO: my message2
226 )",
227                   buf);
228     LogMessage msg3("my message", {"tag1"});
229     msgs.reset();
230     msgs.push_back(std::move(msg3));
231     ASSERT_EQ(ZX_OK, SendLogMessages(listener, msgs));
232 
233     ASSERT_EQ(ZX_OK, log_listener->RunUntilIdle());
234     fflush(buf_file);
235 
236     ASSERT_STR_EQ(R"([00093.892493][1024][1034][] INFO: my message
237 [00093.892493][1024][1034][tag1, tag2] INFO: my message2
238 [00093.892493][1024][1034][tag1] INFO: my message
239 )",
240                   buf);
241     END_TEST;
242 }
243 
TestDroppedLogs()244 bool TestDroppedLogs() {
245     BEGIN_TEST;
246     zx::channel listener, listener_request;
247     ASSERT_EQ(ZX_OK, zx::channel::create(0, &listener, &listener_request));
248 
249     // We expect the log file to be much smaller than this.
250     char buf[1024];
251     memset(buf, 0, sizeof(buf));
252     FILE* buf_file = fmemopen(buf, sizeof(buf), "w");
253 
254     // start listener
255     auto log_listener = fbl::make_unique<LogExporter>(std::move(listener_request), buf_file);
256     log_listener->set_error_handler([](zx_status_t status) {
257         EXPECT_EQ(ZX_ERR_CANCELED, status);
258     });
259 
260     LogMessage msg1("my message1", 1);
261     ASSERT_EQ(ZX_OK, SendLogMessage(listener, std::move(msg1)));
262     LogMessage msg2("my message2", 1);
263     ASSERT_EQ(ZX_OK, SendLogMessage(listener, std::move(msg2)));
264     LogMessage msg3("my message3", 1, 1011);
265     ASSERT_EQ(ZX_OK, SendLogMessage(listener, std::move(msg3)));
266     LogMessage msg4("my message4", 1, 1011);
267     ASSERT_EQ(ZX_OK, SendLogMessage(listener, std::move(msg4)));
268     LogMessage msg5("my message5", 2, 1011);
269     ASSERT_EQ(ZX_OK, SendLogMessage(listener, std::move(msg5)));
270     LogMessage msg6("my message6", 2);
271     ASSERT_EQ(ZX_OK, SendLogMessage(listener, std::move(msg6)));
272 
273     ASSERT_EQ(ZX_OK, log_listener->RunUntilIdle());
274     fflush(buf_file);
275 
276     ASSERT_STR_EQ(R"([00093.892493][1024][1034][] INFO: my message1
277 [00093.892493][1024][1034][] WARNING: Dropped logs count:1
278 [00093.892493][1024][1034][] INFO: my message2
279 [00093.892493][1011][1034][] INFO: my message3
280 [00093.892493][1011][1034][] WARNING: Dropped logs count:1
281 [00093.892493][1011][1034][] INFO: my message4
282 [00093.892493][1011][1034][] INFO: my message5
283 [00093.892493][1011][1034][] WARNING: Dropped logs count:2
284 [00093.892493][1024][1034][] INFO: my message6
285 [00093.892493][1024][1034][] WARNING: Dropped logs count:2
286 )",
287                   buf);
288 
289     END_TEST;
290 }
291 
292 BEGIN_TEST_CASE(LogListenerTests)
293 RUN_TEST(TestLog)
294 RUN_TEST(TestLogMany)
295 RUN_TEST(TestDroppedLogs)
296 END_TEST_CASE(LogListenerTests)
297 
298 } // namespace
299 } // namespace runtests
300