1 // Copyright (c) 2012 The Chromium 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.
5 #include "chrome/test/chromedriver/logging.h"
9 #include "base/basictypes.h"
10 #include "base/command_line.h"
11 #include "base/json/json_reader.h"
12 #include "base/logging.h"
13 #include "base/strings/stringprintf.h"
14 #include "base/time/time.h"
15 #include "chrome/test/chromedriver/capabilities.h"
16 #include "chrome/test/chromedriver/chrome/console_logger.h"
17 #include "chrome/test/chromedriver/chrome/status.h"
18 #include "chrome/test/chromedriver/command_listener_proxy.h"
19 #include "chrome/test/chromedriver/performance_logger.h"
20 #include "chrome/test/chromedriver/session.h"
30 Log::Level g_log_level = Log::kWarning;
32 int64 g_start_time = 0;
34 // Array indices are the Log::Level enum values.
35 const char* kLevelToName[] = {
39 "WARNING", // kWarning
44 const char* LevelToName(Log::Level level) {
45 const int index = level - Log::kAll;
47 CHECK_LT(static_cast<size_t>(index), arraysize(kLevelToName));
48 return kLevelToName[index];
56 const LevelPair kNameToLevel[] = {
58 {"DEBUG", Log::kDebug},
60 {"WARNING", Log::kWarning},
61 {"SEVERE", Log::kError},
65 Log::Level GetLevelFromSeverity(int severity) {
67 case logging::LOG_FATAL:
68 case logging::LOG_ERROR:
70 case logging::LOG_WARNING:
72 case logging::LOG_INFO:
74 case logging::LOG_VERBOSE:
80 WebDriverLog* GetSessionLog() {
81 Session* session = GetThreadLocalSession();
84 return session->driver_log.get();
87 bool InternalIsVLogOn(int vlog_level) {
88 WebDriverLog* session_log = GetSessionLog();
89 Log::Level session_level = session_log ? session_log->min_level() : Log::kOff;
90 Log::Level level = g_log_level < session_level ? g_log_level : session_level;
91 return GetLevelFromSeverity(vlog_level * -1) >= level;
94 bool HandleLogMessage(int severity,
98 const std::string& str) {
99 Log::Level level = GetLevelFromSeverity(severity);
100 std::string message = str.substr(message_start);
102 if (level >= g_log_level) {
103 const char* level_name = LevelToName(level);
104 std::string entry = base::StringPrintf(
106 base::TimeDelta(base::TimeTicks::Now() -
107 base::TimeTicks::FromInternalValue(g_start_time))
111 fprintf(stderr, "%s", entry.c_str());
115 WebDriverLog* session_log = GetSessionLog();
117 session_log->AddEntry(level, message);
124 const char WebDriverLog::kBrowserType[] = "browser";
125 const char WebDriverLog::kDriverType[] = "driver";
126 const char WebDriverLog::kPerformanceType[] = "performance";
128 bool WebDriverLog::NameToLevel(const std::string& name, Log::Level* out_level) {
129 for (size_t i = 0; i < arraysize(kNameToLevel); ++i) {
130 if (name == kNameToLevel[i].name) {
131 *out_level = kNameToLevel[i].level;
138 WebDriverLog::WebDriverLog(const std::string& type, Log::Level min_level)
139 : type_(type), min_level_(min_level), entries_(new base::ListValue()) {
142 WebDriverLog::~WebDriverLog() {
143 VLOG(1) << "Log type '" << type_ << "' lost "
144 << entries_->GetSize() << " entries on destruction";
147 scoped_ptr<base::ListValue> WebDriverLog::GetAndClearEntries() {
148 scoped_ptr<base::ListValue> ret(entries_.release());
149 entries_.reset(new base::ListValue());
153 std::string WebDriverLog::GetFirstErrorMessage() const {
154 for (base::ListValue::iterator it = entries_->begin();
155 it != entries_->end();
157 base::DictionaryValue* log_entry = NULL;
158 (*it)->GetAsDictionary(&log_entry);
159 if (log_entry != NULL) {
161 if (log_entry->GetString("level", &level)) {
162 if (level == kLevelToName[Log::kError]) {
164 if (log_entry->GetString("message", &message))
170 return std::string();
173 void WebDriverLog::AddEntryTimestamped(const base::Time& timestamp,
175 const std::string& source,
176 const std::string& message) {
177 if (level < min_level_)
180 scoped_ptr<base::DictionaryValue> log_entry_dict(new base::DictionaryValue());
181 log_entry_dict->SetDouble("timestamp",
182 static_cast<int64>(timestamp.ToJsTime()));
183 log_entry_dict->SetString("level", LevelToName(level));
185 log_entry_dict->SetString("source", source);
186 log_entry_dict->SetString("message", message);
187 entries_->Append(log_entry_dict.release());
190 const std::string& WebDriverLog::type() const {
194 void WebDriverLog::set_min_level(Level min_level) {
195 min_level_ = min_level;
198 Log::Level WebDriverLog::min_level() const {
203 InitLogging(&InternalIsVLogOn);
204 g_start_time = base::TimeTicks::Now().ToInternalValue();
206 CommandLine* cmd_line = CommandLine::ForCurrentProcess();
207 if (cmd_line->HasSwitch("log-path")) {
208 g_log_level = Log::kInfo;
209 base::FilePath log_path = cmd_line->GetSwitchValuePath("log-path");
211 FILE* redir_stderr = _wfreopen(log_path.value().c_str(), L"w", stderr);
213 FILE* redir_stderr = freopen(log_path.value().c_str(), "w", stderr);
216 printf("Failed to redirect stderr to log file.\n");
220 if (cmd_line->HasSwitch("silent"))
221 g_log_level = Log::kOff;
223 if (cmd_line->HasSwitch("verbose"))
224 g_log_level = Log::kAll;
226 // Turn on VLOG for chromedriver. This is parsed during logging::InitLogging.
227 cmd_line->AppendSwitchASCII("vmodule", "*/chrome/test/chromedriver/*=3");
229 logging::SetMinLogLevel(logging::LOG_WARNING);
230 logging::SetLogItems(false, // enable_process_id
231 false, // enable_thread_id
232 false, // enable_timestamp
233 false); // enable_tickcount
234 logging::SetLogMessageHandler(&HandleLogMessage);
236 logging::LoggingSettings logging_settings;
237 logging_settings.logging_dest = logging::LOG_TO_SYSTEM_DEBUG_LOG;
238 return logging::InitLogging(logging_settings);
241 Status CreateLogs(const Capabilities& capabilities,
242 ScopedVector<WebDriverLog>* out_logs,
243 ScopedVector<DevToolsEventListener>* out_devtools_listeners,
244 ScopedVector<CommandListener>* out_command_listeners) {
245 ScopedVector<WebDriverLog> logs;
246 ScopedVector<DevToolsEventListener> devtools_listeners;
247 ScopedVector<CommandListener> command_listeners;
248 Log::Level browser_log_level = Log::kWarning;
249 const LoggingPrefs& prefs = capabilities.logging_prefs;
251 for (LoggingPrefs::const_iterator iter = prefs.begin();
254 std::string type = iter->first;
255 Log::Level level = iter->second;
256 if (type == WebDriverLog::kPerformanceType) {
257 if (level != Log::kOff) {
258 WebDriverLog* log = new WebDriverLog(type, Log::kAll);
260 PerformanceLogger* perf_log =
261 new PerformanceLogger(log, capabilities.perf_logging_prefs);
262 // We use a proxy for |perf_log|'s |CommandListener| interface.
263 // Otherwise, |perf_log| would be owned by both session->chrome and
264 // |session|, which would lead to memory errors on destruction.
265 // session->chrome will own |perf_log|, and |session| will own |proxy|.
266 // session->command_listeners (the proxy) will be destroyed first.
267 CommandListenerProxy* proxy = new CommandListenerProxy(perf_log);
268 devtools_listeners.push_back(perf_log);
269 command_listeners.push_back(proxy);
271 } else if (type == WebDriverLog::kBrowserType) {
272 browser_log_level = level;
273 } else if (type != WebDriverLog::kDriverType) {
274 // Driver "should" ignore unrecognized log types, per Selenium tests.
275 // For example the Java client passes the "client" log type in the caps,
276 // which the server should never provide.
277 LOG(WARNING) << "Ignoring unrecognized log type: " << type;
280 // Create "browser" log -- should always exist.
281 WebDriverLog* browser_log =
282 new WebDriverLog(WebDriverLog::kBrowserType, browser_log_level);
283 logs.push_back(browser_log);
284 // If the level is OFF, don't even bother listening for DevTools events.
285 if (browser_log_level != Log::kOff)
286 devtools_listeners.push_back(new ConsoleLogger(browser_log));
288 out_logs->swap(logs);
289 out_devtools_listeners->swap(devtools_listeners);
290 out_command_listeners->swap(command_listeners);