15821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)// Copyright (c) 2012 The Chromium Authors. All rights reserved. 25821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)// Use of this source code is governed by a BSD-style license that can be 35821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)// found in the LICENSE file. 45821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 55821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#include "ipc/ipc_logging.h" 65821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 75821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#ifdef IPC_MESSAGE_LOG_ENABLED 85821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#define IPC_MESSAGE_MACROS_LOG_ENABLED 95821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#endif 105821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 115821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#include "base/bind.h" 125821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#include "base/bind_helpers.h" 135821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#include "base/command_line.h" 145821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#include "base/location.h" 155821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#include "base/logging.h" 169ab5563a3196760eb381d102cbb2bc0f7abc6a50Ben Murdoch#include "base/message_loop/message_loop.h" 17868fa2fe829687343ffae624259930155e16dbd8Torne (Richard Coles)#include "base/strings/string_number_conversions.h" 18868fa2fe829687343ffae624259930155e16dbd8Torne (Richard Coles)#include "base/strings/string_util.h" 195821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#include "base/threading/thread.h" 20eb525c5499e34cc9c4b825d6d9e75bb07cc06aceBen Murdoch#include "base/time/time.h" 215821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#include "ipc/ipc_message_utils.h" 222a99a7e74a7f215066514fe81d2bfa6639d9edddTorne (Richard Coles)#include "ipc/ipc_sender.h" 23868fa2fe829687343ffae624259930155e16dbd8Torne (Richard Coles)#include "ipc/ipc_switches.h" 24868fa2fe829687343ffae624259930155e16dbd8Torne (Richard Coles)#include "ipc/ipc_sync_message.h" 255821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 265821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#if defined(OS_POSIX) 275821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#include <unistd.h> 285821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#endif 295821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 305821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#ifdef IPC_MESSAGE_LOG_ENABLED 315821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 325821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)using base::Time; 335821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 345821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)namespace IPC { 355821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 365821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)const int kLogSendDelayMs = 100; 375821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 385821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)// We use a pointer to the function table to avoid any linker dependencies on 395821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)// all the traits used as IPC message parameters. 405821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)LogFunctionMap* Logging::log_function_map_; 415821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 425821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)Logging::Logging() 435821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) : enabled_(false), 445821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) enabled_on_stderr_(false), 455821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) enabled_color_(false), 465821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) queue_invoke_later_pending_(false), 475821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) sender_(NULL), 48c2e0dbddbe15c98d52c4786dac06cb8952a8ae6dTorne (Richard Coles) main_thread_(base::MessageLoop::current()), 495821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) consumer_(NULL) { 505821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#if defined(OS_WIN) 515821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) // getenv triggers an unsafe warning. Simply check how big of a buffer 525821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) // would be needed to fetch the value to see if the enviornment variable is 535821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) // set. 545821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) size_t requiredSize = 0; 555821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) getenv_s(&requiredSize, NULL, 0, "CHROME_IPC_LOGGING"); 565821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) bool logging_env_var_set = (requiredSize != 0); 575821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (requiredSize <= 6) { 585821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) char buffer[6]; 595821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) getenv_s(&requiredSize, buffer, sizeof(buffer), "CHROME_IPC_LOGGING"); 605821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (requiredSize && !strncmp("color", buffer, 6)) 615821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) enabled_color_ = true; 625821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) } 635821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#else // !defined(OS_WIN) 645821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) const char* ipc_logging = getenv("CHROME_IPC_LOGGING"); 655821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) bool logging_env_var_set = (ipc_logging != NULL); 665821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (ipc_logging && !strcmp(ipc_logging, "color")) 675821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) enabled_color_ = true; 685821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#endif //defined(OS_WIN) 695821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (logging_env_var_set) { 705821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) enabled_ = true; 715821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) enabled_on_stderr_ = true; 725821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) } 735821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)} 745821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 755821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)Logging::~Logging() { 765821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)} 775821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 785821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)Logging* Logging::GetInstance() { 795821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return Singleton<Logging>::get(); 805821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)} 815821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 825821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)void Logging::SetConsumer(Consumer* consumer) { 835821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) consumer_ = consumer; 845821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)} 855821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 865821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)void Logging::Enable() { 875821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) enabled_ = true; 885821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)} 895821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 905821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)void Logging::Disable() { 915821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) enabled_ = false; 925821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)} 935821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 945821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)void Logging::OnSendLogs() { 955821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) queue_invoke_later_pending_ = false; 965821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (!sender_) 975821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return; 985821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 995821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) Message* msg = new Message( 1005821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) MSG_ROUTING_CONTROL, IPC_LOGGING_ID, Message::PRIORITY_NORMAL); 1015821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) WriteParam(msg, queued_logs_); 1025821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) queued_logs_.clear(); 1035821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) sender_->Send(msg); 1045821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)} 1055821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1065821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)void Logging::SetIPCSender(IPC::Sender* sender) { 1075821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) sender_ = sender; 1085821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)} 1095821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1105821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)void Logging::OnReceivedLoggingMessage(const Message& message) { 1115821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) std::vector<LogData> data; 1125821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) PickleIterator iter(message); 1135821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (!ReadParam(&message, &iter, &data)) 1145821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return; 1155821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1165821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) for (size_t i = 0; i < data.size(); ++i) { 1175821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) Log(data[i]); 1185821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) } 1195821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)} 1205821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1215821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)void Logging::OnSendMessage(Message* message, const std::string& channel_id) { 1225821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (!Enabled()) 1235821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return; 1245821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1255821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (message->is_reply()) { 1265821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) LogData* data = message->sync_log_data(); 1275821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (!data) 1285821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return; 1295821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1305821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) // This is actually the delayed reply to a sync message. Create a string 1315821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) // of the output parameters, add it to the LogData that was earlier stashed 1325821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) // with the reply, and log the result. 1335821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) GenerateLogData("", *message, data, true); 1345821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) data->channel = channel_id; 1355821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) Log(*data); 1365821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) delete data; 1375821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) message->set_sync_log_data(NULL); 1385821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) } else { 1395821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) // If the time has already been set (i.e. by ChannelProxy), keep that time 1405821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) // instead as it's more accurate. 1415821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (!message->sent_time()) 1425821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) message->set_sent_time(Time::Now().ToInternalValue()); 1435821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) } 1445821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)} 1455821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1465821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)void Logging::OnPreDispatchMessage(const Message& message) { 1475821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) message.set_received_time(Time::Now().ToInternalValue()); 1485821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)} 1495821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1505821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)void Logging::OnPostDispatchMessage(const Message& message, 1515821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) const std::string& channel_id) { 1525821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (!Enabled() || 1535821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) !message.sent_time() || 1545821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) !message.received_time() || 1555821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) message.dont_log()) 1565821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return; 1575821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1585821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) LogData data; 1595821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) GenerateLogData(channel_id, message, &data, true); 1605821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 161c2e0dbddbe15c98d52c4786dac06cb8952a8ae6dTorne (Richard Coles) if (base::MessageLoop::current() == main_thread_) { 1625821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) Log(data); 1635821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) } else { 1645821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) main_thread_->PostTask( 1655821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) FROM_HERE, base::Bind(&Logging::Log, base::Unretained(this), data)); 1665821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) } 1675821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)} 1685821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1695821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)void Logging::GetMessageText(uint32 type, std::string* name, 1705821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) const Message* message, 1715821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) std::string* params) { 1725821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (!log_function_map_) 1735821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return; 1745821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1755821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) LogFunctionMap::iterator it = log_function_map_->find(type); 1765821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (it == log_function_map_->end()) { 1775821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (name) { 1785821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) *name = "[UNKNOWN MSG "; 1795821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) *name += base::IntToString(type); 1805821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) *name += " ]"; 1815821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) } 1825821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return; 1835821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) } 1845821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1855821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) (*it->second)(name, message, params); 1865821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)} 1875821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 1885821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)const char* Logging::ANSIEscape(ANSIColor color) { 1895821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (!enabled_color_) 1905821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return ""; 1915821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) switch (color) { 1925821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) case ANSI_COLOR_RESET: 1935821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return "\033[m"; 1945821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) case ANSI_COLOR_BLACK: 1955821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return "\033[0;30m"; 1965821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) case ANSI_COLOR_RED: 1975821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return "\033[0;31m"; 1985821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) case ANSI_COLOR_GREEN: 1995821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return "\033[0;32m"; 2005821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) case ANSI_COLOR_YELLOW: 2015821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return "\033[0;33m"; 2025821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) case ANSI_COLOR_BLUE: 2035821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return "\033[0;34m"; 2045821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) case ANSI_COLOR_MAGENTA: 2055821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return "\033[0;35m"; 2065821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) case ANSI_COLOR_CYAN: 2075821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return "\033[0;36m"; 2085821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) case ANSI_COLOR_WHITE: 2095821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return "\033[0;37m"; 2105821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) } 2115821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return ""; 2125821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)} 2135821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 2145821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)Logging::ANSIColor Logging::DelayColor(double delay) { 2155821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (delay < 0.1) 2165821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return ANSI_COLOR_GREEN; 2175821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (delay < 0.25) 2185821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return ANSI_COLOR_BLACK; 2195821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (delay < 0.5) 2205821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return ANSI_COLOR_YELLOW; 2215821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return ANSI_COLOR_RED; 2225821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)} 2235821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 2245821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)void Logging::Log(const LogData& data) { 2255821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (consumer_) { 2265821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) // We're in the browser process. 2275821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) consumer_->Log(data); 2285821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) } else { 2295821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) // We're in the renderer or plugin processes. 2305821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (sender_) { 2315821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) queued_logs_.push_back(data); 2325821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (!queue_invoke_later_pending_) { 2335821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) queue_invoke_later_pending_ = true; 234c2e0dbddbe15c98d52c4786dac06cb8952a8ae6dTorne (Richard Coles) base::MessageLoop::current()->PostDelayedTask( 235c2e0dbddbe15c98d52c4786dac06cb8952a8ae6dTorne (Richard Coles) FROM_HERE, 236c2e0dbddbe15c98d52c4786dac06cb8952a8ae6dTorne (Richard Coles) base::Bind(&Logging::OnSendLogs, base::Unretained(this)), 2375821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) base::TimeDelta::FromMilliseconds(kLogSendDelayMs)); 2385821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) } 2395821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) } 2405821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) } 2415821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (enabled_on_stderr_) { 2425821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) std::string message_name; 2435821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (data.message_name.empty()) { 2442a99a7e74a7f215066514fe81d2bfa6639d9edddTorne (Richard Coles) message_name = base::StringPrintf("[unknown type %d]", data.type); 2455821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) } else { 2465821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) message_name = data.message_name; 2475821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) } 2485821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) double receive_delay = 2495821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) (Time::FromInternalValue(data.receive) - 2505821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) Time::FromInternalValue(data.sent)).InSecondsF(); 2515821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) double dispatch_delay = 2525821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) (Time::FromInternalValue(data.dispatch) - 2535821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) Time::FromInternalValue(data.sent)).InSecondsF(); 2545821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) fprintf(stderr, 2555821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) "ipc %s %d %s %s%s %s%s\n %18.5f %s%18.5f %s%18.5f%s\n", 2565821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) data.channel.c_str(), 2575821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) data.routing_id, 2585821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) data.flags.c_str(), 2595821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) ANSIEscape(sender_ ? ANSI_COLOR_BLUE : ANSI_COLOR_CYAN), 2605821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) message_name.c_str(), 2615821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) ANSIEscape(ANSI_COLOR_RESET), 2625821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) data.params.c_str(), 2635821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) Time::FromInternalValue(data.sent).ToDoubleT(), 2645821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) ANSIEscape(DelayColor(receive_delay)), 2655821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) Time::FromInternalValue(data.receive).ToDoubleT(), 2665821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) ANSIEscape(DelayColor(dispatch_delay)), 2675821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) Time::FromInternalValue(data.dispatch).ToDoubleT(), 2685821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) ANSIEscape(ANSI_COLOR_RESET) 2695821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) ); 2705821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) } 2715821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)} 2725821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 2735821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)void GenerateLogData(const std::string& channel, const Message& message, 2745821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) LogData* data, bool get_params) { 2755821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (message.is_reply()) { 2765821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) // "data" should already be filled in. 2775821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) std::string params; 2785821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) Logging::GetMessageText(data->type, NULL, &message, ¶ms); 2795821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 2805821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (!data->params.empty() && !params.empty()) 2815821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) data->params += ", "; 2825821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 2835821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) data->flags += " DR"; 2845821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 2855821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) data->params += params; 2865821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) } else { 2875821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) std::string flags; 2885821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (message.is_sync()) 2895821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) flags = "S"; 2905821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 2915821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (message.is_reply()) 2925821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) flags += "R"; 2935821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 2945821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (message.is_reply_error()) 2955821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) flags += "E"; 2965821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 2975821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) std::string params, message_name; 2985821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) Logging::GetMessageText(message.type(), &message_name, &message, 2995821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) get_params ? ¶ms : NULL); 3005821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 3015821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) data->channel = channel; 3025821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) data->routing_id = message.routing_id(); 3035821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) data->type = message.type(); 3045821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) data->flags = flags; 3055821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) data->sent = message.sent_time(); 3065821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) data->receive = message.received_time(); 3075821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) data->dispatch = Time::Now().ToInternalValue(); 3085821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) data->params = params; 3095821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) data->message_name = message_name; 3105821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) } 3115821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)} 3125821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 3135821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)} 3145821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 3155821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#endif // IPC_MESSAGE_LOG_ENABLED 316