Add Logger observer and helper class
[WebKit-https.git] / Tools / TestWebKitAPI / Tests / WebCore / Logging.cpp
1 /*
2  * Copyright (C) 2017 Apple Inc. All rights reserved.
3  *
4  * Redistribution and use in source and binary forms, with or without
5  * modification, are permitted provided that the following conditions
6  * are met:
7  * 1. Redistributions of source code must retain the above copyright
8  *    notice, this list of conditions and the following disclaimer.
9  * 2. Redistributions in binary form must reproduce the above copyright
10  *    notice, this list of conditions and the following disclaimer in the
11  *    documentation and/or other materials provided with the distribution.
12  *
13  * THIS SOFTWARE IS PROVIDED BY APPLE INC. AND ITS CONTRIBUTORS ``AS IS''
14  * AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO,
15  * THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR
16  * PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL APPLE INC. OR ITS CONTRIBUTORS
17  * BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
18  * CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
19  * SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
20  * INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
21  * CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
22  * ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF
23  * THE POSSIBILITY OF SUCH DAMAGE.
24  */
25
26 #include "config.h"
27 #include "WTFStringUtilities.h"
28 #include <pal/Logger.h>
29 #include <wtf/Assertions.h>
30 #include <wtf/MainThread.h>
31
32 #define LOG_CHANNEL_PREFIX Test
33
34 using namespace PAL;
35 using namespace WTF;
36
37 const char* logTestingSubsystem = "com.webkit.testing";
38
39 DEFINE_LOG_CHANNEL(Channel1, logTestingSubsystem);
40 DEFINE_LOG_CHANNEL(Channel2, logTestingSubsystem);
41 DEFINE_LOG_CHANNEL(Channel3, logTestingSubsystem);
42 DEFINE_LOG_CHANNEL(Channel4, logTestingSubsystem);
43
44 static WTFLogChannel* testLogChannels[] = {
45     &TestChannel1,
46     &TestChannel2,
47     &TestChannel3,
48     &TestChannel4,
49 };
50 static const size_t logChannelCount = sizeof(testLogChannels) / sizeof(testLogChannels[0]);
51
52 // Define the following to enable all tests. Disabled by default because replacing stderr with a
53 // non-blocking pipe fails on some of the bots.
54 #define TEST_OUTPUT 0
55
56 namespace TestWebKitAPI {
57
58 class LoggingTest : public testing::Test, public LogHelper {
59 public:
60     LoggingTest()
61         : m_logger { Logger::create(this) }
62     {
63     }
64
65     void SetUp() final
66     {
67         WTF::initializeMainThread();
68
69         // Replace stderr with a non-blocking pipe that we can read from.
70         pipe(m_descriptors);
71         fcntl(m_descriptors[0], F_SETFL, fcntl(m_descriptors[0], F_GETFL, 0) | O_NONBLOCK);
72         dup2(m_descriptors[1], STDERR_FILENO);
73         close(m_descriptors[1]);
74
75         m_stderr = fdopen(m_descriptors[0], "r");
76
77         WTFInitializeLogChannelStatesFromString(testLogChannels, logChannelCount, "all");
78         WTFSetLogChannelLevel(&TestChannel1, WTFLogLevelError);
79         WTFSetLogChannelLevel(&TestChannel2, WTFLogLevelError);
80         WTFSetLogChannelLevel(&TestChannel3, WTFLogLevelError);
81         WTFSetLogChannelLevel(&TestChannel4, WTFLogLevelError);
82     }
83
84     void TearDown() override
85     {
86         close(m_descriptors[0]);
87         fclose(m_stderr);
88     }
89
90     String output()
91     {
92         char buffer[1024];
93         StringBuilder result;
94         char* line;
95
96         while ((line = fgets(buffer, sizeof(buffer), m_stderr)))
97             result.append(line);
98
99         return result.toString();
100     }
101
102     const Logger& logger() const final { return m_logger.get(); }
103     const char* className() const final { return "LoggingTest"; }
104     WTFLogChannel& logChannel() const final { return TestChannel1; }
105
106 private:
107
108     Ref<Logger> m_logger;
109     int m_descriptors[2];
110     FILE* m_stderr;
111 };
112
113 TEST_F(LoggingTest, Initialization)
114 {
115     EXPECT_EQ(TestChannel1.state, WTFLogChannelOn);
116     EXPECT_EQ(TestChannel2.state, WTFLogChannelOn);
117     EXPECT_EQ(TestChannel3.state, WTFLogChannelOn);
118     EXPECT_EQ(TestChannel4.state, WTFLogChannelOn);
119
120     EXPECT_EQ(TestChannel1.level, WTFLogLevelError);
121     EXPECT_EQ(TestChannel2.level, WTFLogLevelError);
122     EXPECT_EQ(TestChannel3.level, WTFLogLevelError);
123     EXPECT_EQ(TestChannel4.level, WTFLogLevelError);
124
125     TestChannel1.state = WTFLogChannelOff;
126     WTFInitializeLogChannelStatesFromString(testLogChannels, logChannelCount, "Channel1");
127     EXPECT_EQ(TestChannel1.level, WTFLogLevelError);
128     EXPECT_EQ(TestChannel1.state, WTFLogChannelOn);
129
130     TestChannel1.state = WTFLogChannelOff;
131     WTFInitializeLogChannelStatesFromString(testLogChannels, logChannelCount, "Channel1=foo");
132     EXPECT_EQ(TestChannel1.level, WTFLogLevelError);
133 #if TEST_OUTPUT
134     EXPECT_TRUE(output().contains("Unknown logging level: foo", false));
135 #endif
136
137     WTFInitializeLogChannelStatesFromString(testLogChannels, logChannelCount, "Channel1=warning");
138     EXPECT_EQ(TestChannel1.level, WTFLogLevelWarning);
139     EXPECT_EQ(TestChannel2.level, WTFLogLevelError);
140     EXPECT_EQ(TestChannel3.level, WTFLogLevelError);
141     EXPECT_EQ(TestChannel4.level, WTFLogLevelError);
142
143     WTFInitializeLogChannelStatesFromString(testLogChannels, logChannelCount, "Channel4=   debug, Channel3 = info,Channel2=notice");
144     EXPECT_EQ(TestChannel1.level, WTFLogLevelWarning);
145     EXPECT_EQ(TestChannel2.level, WTFLogLevelNotice);
146     EXPECT_EQ(TestChannel3.level, WTFLogLevelInfo);
147     EXPECT_EQ(TestChannel4.level, WTFLogLevelDebug);
148
149     WTFInitializeLogChannelStatesFromString(testLogChannels, logChannelCount, "-all");
150     EXPECT_EQ(TestChannel1.state, WTFLogChannelOff);
151     EXPECT_EQ(TestChannel2.state, WTFLogChannelOff);
152     EXPECT_EQ(TestChannel3.state, WTFLogChannelOff);
153     EXPECT_EQ(TestChannel4.state, WTFLogChannelOff);
154
155     WTFInitializeLogChannelStatesFromString(testLogChannels, logChannelCount, "all");
156     EXPECT_EQ(TestChannel1.state, WTFLogChannelOn);
157     EXPECT_EQ(TestChannel2.state, WTFLogChannelOn);
158     EXPECT_EQ(TestChannel3.state, WTFLogChannelOn);
159     EXPECT_EQ(TestChannel4.state, WTFLogChannelOn);
160 }
161
162 TEST_F(LoggingTest, WTFWillLogWithLevel)
163 {
164     EXPECT_EQ(TestChannel1.state, WTFLogChannelOn);
165     EXPECT_EQ(TestChannel2.state, WTFLogChannelOn);
166     EXPECT_EQ(TestChannel3.state, WTFLogChannelOn);
167     EXPECT_EQ(TestChannel4.state, WTFLogChannelOn);
168
169     EXPECT_EQ(TestChannel1.level, WTFLogLevelError);
170     EXPECT_EQ(TestChannel2.level, WTFLogLevelError);
171     EXPECT_EQ(TestChannel3.level, WTFLogLevelError);
172     EXPECT_EQ(TestChannel4.level, WTFLogLevelError);
173
174     EXPECT_TRUE(WTFWillLogWithLevel(&TestChannel1, WTFLogLevelError));
175     EXPECT_TRUE(WTFWillLogWithLevel(&TestChannel2, WTFLogLevelError));
176     EXPECT_TRUE(WTFWillLogWithLevel(&TestChannel3, WTFLogLevelError));
177     EXPECT_TRUE(WTFWillLogWithLevel(&TestChannel4, WTFLogLevelError));
178
179     EXPECT_FALSE(WTFWillLogWithLevel(&TestChannel1, WTFLogLevelInfo));
180     EXPECT_FALSE(WTFWillLogWithLevel(&TestChannel2, WTFLogLevelInfo));
181     EXPECT_FALSE(WTFWillLogWithLevel(&TestChannel3, WTFLogLevelInfo));
182     EXPECT_FALSE(WTFWillLogWithLevel(&TestChannel4, WTFLogLevelInfo));
183
184     TestChannel1.state = WTFLogChannelOff;
185     EXPECT_FALSE(WTFWillLogWithLevel(&TestChannel1, WTFLogLevelError));
186     EXPECT_FALSE(WTFWillLogWithLevel(&TestChannel1, WTFLogLevelInfo));
187
188     TestChannel1.state = WTFLogChannelOn;
189     EXPECT_TRUE(WTFWillLogWithLevel(&TestChannel1, WTFLogLevelError));
190     EXPECT_FALSE(WTFWillLogWithLevel(&TestChannel1, WTFLogLevelInfo));
191
192     TestChannel1.level = WTFLogLevelInfo;
193     EXPECT_TRUE(WTFWillLogWithLevel(&TestChannel1, WTFLogLevelError));
194     EXPECT_TRUE(WTFWillLogWithLevel(&TestChannel1, WTFLogLevelInfo));
195 }
196
197 #if TEST_OUTPUT
198 TEST_F(LoggingTest, LOG)
199 {
200     LOG(Channel1, "Log message.");
201     EXPECT_TRUE(output().contains("Log Message.", false));
202 }
203
204 TEST_F(LoggingTest, LOG_WITH_LEVEL)
205 {
206     LOG_WITH_LEVEL(Channel1, WTFLogLevelError, "Go and boil your bottoms, you sons of a silly person.");
207     EXPECT_TRUE(output().contains("sons of a silly person.", false));
208
209     LOG_WITH_LEVEL(Channel1, WTFLogLevelWarning, "You don't frighten us, English pig dogs.");
210     EXPECT_EQ(0u, output().length());
211
212     WTFSetLogChannelLevel(&TestChannel1, WTFLogLevelInfo);
213     LOG_WITH_LEVEL(Channel1, WTFLogLevelWarning, "I'm French. Why do you think I have this outrageous accent, you silly king?");
214     EXPECT_TRUE(output().contains("outrageous accent", false));
215
216     LOG_WITH_LEVEL(Channel1, WTFLogLevelDebug, "You don't frighten us with your silly knees-bent running around advancing behavior!");
217     EXPECT_EQ(0u, output().length());
218
219     WTFSetLogChannelLevel(&TestChannel1, WTFLogLevelDebug);
220     LOG_WITH_LEVEL(Channel1, WTFLogLevelDebug, "Go and tell your master that we have been charged by God with a sacred quest.");
221     EXPECT_TRUE(output().contains("sacred quest", false));
222 }
223
224 TEST_F(LoggingTest, RELEASE_LOG)
225 {
226     RELEASE_LOG(Channel1, "Log message.");
227     EXPECT_TRUE(output().contains("Log Message.", false));
228 }
229
230 TEST_F(LoggingTest, RELEASE_LOG_IF)
231 {
232     bool enabled = true;
233     RELEASE_LOG_IF(enabled, Channel1, "Your mother was a hamster,");
234     EXPECT_TRUE(output().contains("hamster,", false));
235
236     enabled = false;
237     RELEASE_LOG_IF(enabled, Channel1, "and your father smelt of elderberries ...");
238     EXPECT_EQ(0u, output().length());
239 }
240
241 TEST_F(LoggingTest, RELEASE_LOG_WITH_LEVEL)
242 {
243     RELEASE_LOG_WITH_LEVEL(Channel1, WTFLogLevelError, "You don't frighten us, English pig dogs.");
244     EXPECT_TRUE(output().contains("pig dogs.", false));
245
246     RELEASE_LOG_WITH_LEVEL(Channel1, WTFLogLevelWarning, "Go and boil your bottoms, you sons of a silly person.");
247     EXPECT_EQ(0u, output().length());
248
249     WTFSetLogChannelLevel(&TestChannel1, WTFLogLevelInfo);
250     RELEASE_LOG_WITH_LEVEL(Channel1, WTFLogLevelWarning, "I'm French. Why do you think I have this outrageous accent, you silly king?");
251     EXPECT_TRUE(output().contains("outrageous accent", false));
252
253     RELEASE_LOG_WITH_LEVEL(Channel1, WTFLogLevelDebug, "You don't frighten us with your silly knees-bent running around advancing behavior!");
254     EXPECT_EQ(0u, output().length());
255
256     WTFSetLogChannelLevel(&TestChannel1, WTFLogLevelDebug);
257     RELEASE_LOG_WITH_LEVEL(Channel1, WTFLogLevelDebug, "Go and tell your master that we have been charged by God with a sacred quest.");
258     EXPECT_TRUE(output().contains("sacred quest", false));
259 }
260
261 TEST_F(LoggingTest, RELEASE_LOG_WITH_LEVEL_IF)
262 {
263     bool enabled = true;
264     RELEASE_LOG_WITH_LEVEL_IF(enabled, Channel1, WTFLogLevelError, "Is there someone else up there that we can talk to?");
265     EXPECT_TRUE(output().contains("someone else", false));
266
267     RELEASE_LOG_WITH_LEVEL_IF(enabled, Channel1, WTFLogLevelDebug, "No, now go away");
268     EXPECT_EQ(0u, output().length());
269
270     enabled = false;
271     RELEASE_LOG_WITH_LEVEL_IF(enabled, Channel1, WTFLogLevelWarning, "or I shall taunt you a second time! %i", 12);
272     EXPECT_EQ(0u, output().length());
273 }
274
275 TEST_F(LoggingTest, Logger)
276 {
277     Ref<Logger> logger = Logger::create(this);
278     EXPECT_TRUE(logger->enabled());
279
280     WTFSetLogChannelLevel(&TestChannel1, WTFLogLevelError);
281     EXPECT_TRUE(logger->willLog(TestChannel1, WTFLogLevelError));
282     logger->error(TestChannel1, "You're using coconuts!");
283     EXPECT_TRUE(output().contains("You're using coconuts!", false));
284     logger->warning(TestChannel1, "You're using coconuts!");
285     EXPECT_EQ(0u, output().length());
286     logger->notice(TestChannel1, "You're using coconuts!");
287     EXPECT_EQ(0u, output().length());
288     logger->info(TestChannel1, "You're using coconuts!");
289     EXPECT_EQ(0u, output().length());
290     logger->debug(TestChannel1, "You're using coconuts!");
291     EXPECT_EQ(0u, output().length());
292
293     logger->error(TestChannel1, Logger::MethodAndPointer("LoggingTest::Logger", this) , ": test output");
294     EXPECT_TRUE(output().contains("LoggingTest::Logger(", false));
295
296     logger->error(TestChannel1, "What is ", 1, " + " , 12.5F, "?");
297     EXPECT_TRUE(output().contains("What is 1 + 12.5?", false));
298
299     logger->error(TestChannel1, "What, ", "ridden on a horse?");
300     EXPECT_TRUE(output().contains("What, ridden on a horse?", false));
301
302     logger->setEnabled(this, false);
303     EXPECT_FALSE(logger->enabled());
304     logger->error(TestChannel1, "You've got two empty halves of coconuts");
305     EXPECT_EQ(0u, output().length());
306
307     logger->setEnabled(this, true);
308     EXPECT_TRUE(logger->enabled());
309     logger->error(TestChannel1, "You've got ", 2, " empty halves of ", "coconuts!");
310     EXPECT_TRUE(output().contains("You've got 2 empty halves of coconuts!", false));
311
312     WTFSetLogChannelLevel(&TestChannel1, WTFLogLevelError);
313     logger->logAlways(TestChannel1, "I shall taunt you a second time!");
314     EXPECT_TRUE(output().contains("I shall taunt you a second time!", false));
315
316     logger->setEnabled(this, false);
317     EXPECT_FALSE(logger->willLog(TestChannel1, WTFLogLevelError));
318     EXPECT_FALSE(logger->willLog(TestChannel1, WTFLogLevelWarning));
319     EXPECT_FALSE(logger->willLog(TestChannel1, WTFLogLevelNotice));
320     EXPECT_FALSE(logger->willLog(TestChannel1, WTFLogLevelInfo));
321     EXPECT_FALSE(logger->willLog(TestChannel1, WTFLogLevelDebug));
322     EXPECT_FALSE(logger->enabled());
323     logger->logAlways(TestChannel1, "You've got two empty halves of coconuts");
324     EXPECT_EQ(0u, output().length());
325
326     logger->setEnabled(this, true);
327     AtomicString string1("AtomicString", AtomicString::ConstructFromLiteral);
328     const AtomicString string2("const AtomicString", AtomicString::ConstructFromLiteral);
329     logger->logAlways(TestChannel1, string1, " and ", string2);
330     EXPECT_TRUE(output().contains("AtomicString and const AtomicString", false));
331
332     String string3("String");
333     const String string4("const String");
334     logger->logAlways(TestChannel1, string3, " and ", string4);
335     EXPECT_TRUE(output().contains("String and const String", false));
336 }
337
338 TEST_F(LoggingTest, LogHelper)
339 {
340     EXPECT_TRUE(logger().enabled());
341
342     StringBuilder builder;
343     builder.appendLiteral("LoggingTest::TestBody(0x");
344     appendUnsigned64AsHex(reinterpret_cast<uintptr_t>(this), builder);
345     builder.appendLiteral(")");
346     String signature = builder.toString();
347
348     ALWAYS_LOG();
349     EXPECT_TRUE(this->output().contains(signature, false));
350
351     ALWAYS_LOG("Welcome back", " my friends", " to the show", " that never ends");
352     String result = this->output();
353     EXPECT_TRUE(result.contains(signature, false));
354     EXPECT_TRUE(result.contains("to the show that never", false));
355
356     WTFSetLogChannelLevel(&TestChannel1, WTFLogLevelWarning);
357     EXPECT_TRUE(willLog(WTFLogLevelWarning));
358
359     ERROR_LOG("We're so glad you could attend");
360     EXPECT_TRUE(output().contains("We're so glad you could attend", false));
361
362     WARNING_LOG("Come inside! ", "Come inside!");
363     EXPECT_TRUE(output().contains("Come inside! Come inside!", false));
364
365     NOTICE_LOG("There behind a glass is a real blade of grass");
366     EXPECT_EQ(0u, output().length());
367
368     INFO_LOG("be careful as you pass.");
369     EXPECT_EQ(0u, output().length());
370
371     DEBUG_LOG("Move along! Move along!");
372     EXPECT_EQ(0u, output().length());
373 }
374
375 class LogObserver : public Logger::Observer {
376 public:
377     LogObserver() = default;
378
379     String log()
380     {
381         String log = m_logBuffer.toString();
382         m_logBuffer.clear();
383
384         return log;
385     }
386
387     WTFLogChannel channel() const { return m_lastChannel; }
388
389 private:
390     void didLogMessage(const WTFLogChannel& channel, const String& logMessage) final
391     {
392         m_logBuffer.append(logMessage);
393         m_lastChannel = channel;
394     }
395
396     StringBuilder m_logBuffer;
397     WTFLogChannel m_lastChannel;
398 };
399
400 TEST_F(LoggingTest, LogObserver)
401 {
402     LogObserver observer;
403
404     EXPECT_TRUE(logger().enabled());
405
406     logger().addObserver(observer);
407     ALWAYS_LOG("testing 1, 2, 3");
408     EXPECT_TRUE(this->output().contains("testing 1, 2, 3", false));
409     EXPECT_TRUE(observer.log().contains("testing 1, 2, 3", false));
410     EXPECT_STREQ(observer.channel().name, logChannel().name);
411
412     logger().removeObserver(observer);
413     ALWAYS_LOG("testing ", 1, ", ", 2, ", 3");
414     EXPECT_TRUE(this->output().contains("testing 1, 2, 3", false));
415     EXPECT_EQ(0u, observer.log().length());
416 }
417
418 #endif
419
420 } // namespace TestWebKitAPI