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 <lib/logger/logger.h>
6 
7 #include <fuchsia/logger/c/fidl.h>
8 #include <lib/async-loop/cpp/loop.h>
9 #include <lib/syslog/global.h>
10 #include <unittest/unittest.h>
11 
12 #include <fcntl.h>
13 
14 #include <utility>
15 
16 __BEGIN_CDECLS
17 
18 // This does not come from header file as this function should only be used in
19 // tests and is not for general use.
20 void fx_log_reset_global(void);
21 
22 __END_CDECLS
23 namespace {
24 
ends_with(const char * str,const char * suffix)25 bool ends_with(const char* str, const char* suffix) {
26     size_t str_len = strlen(str);
27     size_t suffix_len = strlen(suffix);
28     if (str_len < suffix_len) {
29         return false;
30     }
31     str += str_len - suffix_len;
32     return strcmp(str, suffix) == 0;
33 }
34 
35 class Fixture {
36 public:
Fixture()37     Fixture()
38         : fds_valid_(false), loop_(&kAsyncLoopConfigNoAttachToThread), error_status_(0) {}
~Fixture()39     ~Fixture() {
40         fx_log_reset_global();
41         if (fds_valid_) {
42             close(pipefd_[0]);
43             close(pipefd_[1]);
44         }
45     }
46 
error_status() const47     zx_status_t error_status() const {
48         return error_status_;
49     }
50 
CreateLogger()51     bool CreateLogger() {
52         ASSERT_NE(pipe2(pipefd_, O_NONBLOCK), -1, "");
53         zx::channel local, remote;
54         ASSERT_EQ(ZX_OK, zx::channel::create(0, &local, &remote));
55         logger_ = fbl::make_unique<logger::LoggerImpl>(std::move(remote), pipefd_[0]);
56         ASSERT_EQ(ZX_OK, logger_->Begin(loop_.dispatcher()));
57         logger_handle_.reset(local.release());
58         logger_->set_error_handler([this](zx_status_t status) {
59             error_status_ = status;
60         });
61         return true;
62     }
63 
ResetLoggerHandle()64     void ResetLoggerHandle() {
65         logger_handle_.reset();
66     }
67 
ResetSocket()68     void ResetSocket() {
69         socket_.reset();
70     }
71 
ConnectToLogger()72     bool ConnectToLogger() {
73         ASSERT_TRUE(logger_handle_);
74         zx::socket local, remote;
75         ASSERT_EQ(ZX_OK, zx::socket::create(ZX_SOCKET_DATAGRAM, &local, &remote));
76         fuchsia_logger_LogSinkConnectRequest req;
77         memset(&req, 0, sizeof(req));
78         req.hdr.ordinal = fuchsia_logger_LogSinkConnectOrdinal;
79         req.socket = FIDL_HANDLE_PRESENT;
80         zx_handle_t handles[1] = {remote.release()};
81         ASSERT_EQ(ZX_OK, logger_handle_.write(0, &req, sizeof(req), handles, 1));
82         loop_.RunUntilIdle();
83         socket_.reset(local.release());
84         return true;
85     }
86 
InitSyslog(const char ** tags,size_t ntags)87     bool InitSyslog(const char** tags, size_t ntags) {
88         ASSERT_TRUE(socket_);
89         fx_logger_config_t config = {.min_severity = FX_LOG_INFO,
90                                      .console_fd = -1,
91                                      .log_service_channel = socket_.release(),
92                                      .tags = tags,
93                                      .num_tags = ntags};
94 
95         ASSERT_EQ(ZX_OK, fx_log_init_with_config(&config));
96         return true;
97     }
98 
FullSetup()99     bool FullSetup() {
100         ASSERT_TRUE(CreateLogger());
101         ASSERT_TRUE(ConnectToLogger());
102         ASSERT_TRUE(InitSyslog(nullptr, 0));
103         return true;
104     }
105 
RunLoop()106     void RunLoop() {
107         loop_.RunUntilIdle();
108         fsync(pipefd_[0]);
109     }
110 
read_buffer()111     const char* read_buffer() {
112         memset(buf_, 0, sizeof(buf_));
113         read(pipefd_[1], &buf_, sizeof(buf_));
114         return buf_;
115     }
116 
117 private:
118     bool fds_valid_;
119     char buf_[4096]; // should be enough for logs
120     async::Loop loop_;
121     zx_status_t error_status_;
122     fbl::unique_ptr<logger::LoggerImpl> logger_;
123     zx::channel logger_handle_;
124     zx::socket socket_;
125     int pipefd_[2];
126 };
127 
TestLogSimple(void)128 bool TestLogSimple(void) {
129     BEGIN_TEST;
130     Fixture fixture;
131     ASSERT_TRUE(fixture.FullSetup());
132     FX_LOG(INFO, nullptr, "test_message");
133     fixture.RunLoop();
134     const char* out = fixture.read_buffer();
135     ASSERT_TRUE(ends_with(out, "test_message\n"), out);
136     END_TEST;
137 }
138 
TestLogMultipleMsgs(void)139 bool TestLogMultipleMsgs(void) {
140     BEGIN_TEST;
141     Fixture fixture;
142     ASSERT_TRUE(fixture.FullSetup());
143     FX_LOG(INFO, nullptr, "test_message");
144     fixture.RunLoop();
145     const char* out = fixture.read_buffer();
146     ASSERT_TRUE(ends_with(out, "INFO: test_message\n"), out);
147     FX_LOG(INFO, nullptr, "test_message2");
148     fixture.RunLoop();
149     out = fixture.read_buffer();
150     ASSERT_TRUE(ends_with(out, "INFO: test_message2\n"), out);
151     END_TEST;
152 }
153 
TestLogWithTag(void)154 bool TestLogWithTag(void) {
155     BEGIN_TEST;
156     Fixture fixture;
157     ASSERT_TRUE(fixture.FullSetup());
158     FX_LOG(INFO, "tag", "test_message");
159     fixture.RunLoop();
160     const char* out = fixture.read_buffer();
161     ASSERT_TRUE(ends_with(out, "[tag] INFO: test_message\n"), out);
162     END_TEST;
163 }
164 
TestLogWithMultipleTags(void)165 bool TestLogWithMultipleTags(void) {
166     BEGIN_TEST;
167     Fixture fixture;
168     ASSERT_TRUE(fixture.CreateLogger());
169     ASSERT_TRUE(fixture.ConnectToLogger());
170     const char* gtags[] = {"gtag1", "gtag2"};
171     ASSERT_TRUE(fixture.InitSyslog(gtags, 2));
172     FX_LOG(INFO, "tag", "test_message");
173     fixture.RunLoop();
174     const char* out = fixture.read_buffer();
175     ASSERT_TRUE(ends_with(out, "[gtag1, gtag2, tag] INFO: test_message\n"), out);
176     END_TEST;
177 }
178 
TestLogSeverity(void)179 bool TestLogSeverity(void) {
180     BEGIN_TEST;
181     Fixture fixture;
182     ASSERT_TRUE(fixture.FullSetup());
183     FX_LOG(INFO, "", "test_message");
184     fixture.RunLoop();
185     const char* out = fixture.read_buffer();
186     ASSERT_TRUE(ends_with(out, "[] INFO: test_message\n"), out);
187 
188     FX_LOG(WARNING, "", "test_message");
189     fixture.RunLoop();
190     out = fixture.read_buffer();
191     ASSERT_TRUE(ends_with(out, "[] WARNING: test_message\n"), out);
192 
193     FX_LOG(ERROR, "", "test_message");
194     fixture.RunLoop();
195     out = fixture.read_buffer();
196     ASSERT_TRUE(ends_with(out, "[] ERROR: test_message\n"), out);
197 
198     END_TEST;
199 }
200 
TestLogWhenLoggerHandleDies(void)201 bool TestLogWhenLoggerHandleDies(void) {
202     BEGIN_TEST;
203     Fixture fixture;
204     ASSERT_TRUE(fixture.FullSetup());
205     fixture.ResetLoggerHandle();
206     fixture.RunLoop();
207     FX_LOG(INFO, "tag", "test_message");
208     fixture.RunLoop();
209     const char* out = fixture.read_buffer();
210     ASSERT_TRUE(ends_with(out, "[tag] INFO: test_message\n"), out);
211     ASSERT_EQ(ZX_OK, fixture.error_status());
212     END_TEST;
213 }
214 
TestLoggerDiesWithSocket(void)215 bool TestLoggerDiesWithSocket(void) {
216     BEGIN_TEST;
217     Fixture fixture;
218     ASSERT_TRUE(fixture.CreateLogger());
219     ASSERT_TRUE(fixture.ConnectToLogger());
220     fixture.ResetSocket();
221     fixture.RunLoop();
222     ASSERT_EQ(ZX_ERR_PEER_CLOSED, fixture.error_status());
223     END_TEST;
224 }
225 
TestLoggerDiesWithChannelWhenNoConnectCalled(void)226 bool TestLoggerDiesWithChannelWhenNoConnectCalled(void) {
227     BEGIN_TEST;
228     Fixture fixture;
229     ASSERT_TRUE(fixture.CreateLogger());
230     fixture.RunLoop();
231     ASSERT_EQ(ZX_OK, fixture.error_status());
232     fixture.ResetLoggerHandle();
233     fixture.RunLoop();
234     ASSERT_EQ(ZX_ERR_PEER_CLOSED, fixture.error_status());
235     END_TEST;
236 }
237 
238 } // namespace
239 
240 BEGIN_TEST_CASE(logger_tests)
RUN_TEST(TestLogSimple)241 RUN_TEST(TestLogSimple)
242 RUN_TEST(TestLogSeverity)
243 RUN_TEST(TestLogMultipleMsgs)
244 RUN_TEST(TestLogWithTag)
245 RUN_TEST(TestLogWithMultipleTags)
246 RUN_TEST(TestLogWhenLoggerHandleDies)
247 RUN_TEST(TestLoggerDiesWithSocket)
248 RUN_TEST(TestLoggerDiesWithChannelWhenNoConnectCalled)
249 END_TEST_CASE(logger_tests)
250 
251 int main(int argc, char** argv) {
252     return unittest_run_all_tests(argc, argv) ? 0 : -1;
253 }
254