Fix reconnect in case of empty global network policy.
[chromium-blink-merge.git] / ipc / ipc_logging.cc
blob65d88901d93c7cdc9fe743a71277c0e45add7d6d
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 "ipc/ipc_logging.h"
7 #ifdef IPC_MESSAGE_LOG_ENABLED
8 #define IPC_MESSAGE_MACROS_LOG_ENABLED
9 #endif
11 #include "base/bind.h"
12 #include "base/bind_helpers.h"
13 #include "base/command_line.h"
14 #include "base/location.h"
15 #include "base/logging.h"
16 #include "base/message_loop/message_loop.h"
17 #include "base/strings/string_number_conversions.h"
18 #include "base/strings/string_util.h"
19 #include "base/threading/thread.h"
20 #include "base/time/time.h"
21 #include "ipc/ipc_message_utils.h"
22 #include "ipc/ipc_sender.h"
23 #include "ipc/ipc_switches.h"
24 #include "ipc/ipc_sync_message.h"
26 #if defined(OS_POSIX)
27 #include <unistd.h>
28 #endif
30 #ifdef IPC_MESSAGE_LOG_ENABLED
32 using base::Time;
34 namespace IPC {
36 const int kLogSendDelayMs = 100;
38 // We use a pointer to the function table to avoid any linker dependencies on
39 // all the traits used as IPC message parameters.
40 LogFunctionMap* Logging::log_function_map_;
42 Logging::Logging()
43 : enabled_(false),
44 enabled_on_stderr_(false),
45 enabled_color_(false),
46 queue_invoke_later_pending_(false),
47 sender_(NULL),
48 main_thread_(base::MessageLoop::current()),
49 consumer_(NULL) {
50 #if defined(OS_WIN)
51 // getenv triggers an unsafe warning. Simply check how big of a buffer
52 // would be needed to fetch the value to see if the enviornment variable is
53 // set.
54 size_t requiredSize = 0;
55 getenv_s(&requiredSize, NULL, 0, "CHROME_IPC_LOGGING");
56 bool logging_env_var_set = (requiredSize != 0);
57 if (requiredSize <= 6) {
58 char buffer[6];
59 getenv_s(&requiredSize, buffer, sizeof(buffer), "CHROME_IPC_LOGGING");
60 if (requiredSize && !strncmp("color", buffer, 6))
61 enabled_color_ = true;
63 #else // !defined(OS_WIN)
64 const char* ipc_logging = getenv("CHROME_IPC_LOGGING");
65 bool logging_env_var_set = (ipc_logging != NULL);
66 if (ipc_logging && !strcmp(ipc_logging, "color"))
67 enabled_color_ = true;
68 #endif //defined(OS_WIN)
69 if (logging_env_var_set) {
70 enabled_ = true;
71 enabled_on_stderr_ = true;
75 Logging::~Logging() {
78 Logging* Logging::GetInstance() {
79 return Singleton<Logging>::get();
82 void Logging::SetConsumer(Consumer* consumer) {
83 consumer_ = consumer;
86 void Logging::Enable() {
87 enabled_ = true;
90 void Logging::Disable() {
91 enabled_ = false;
94 void Logging::OnSendLogs() {
95 queue_invoke_later_pending_ = false;
96 if (!sender_)
97 return;
99 Message* msg = new Message(
100 MSG_ROUTING_CONTROL, IPC_LOGGING_ID, Message::PRIORITY_NORMAL);
101 WriteParam(msg, queued_logs_);
102 queued_logs_.clear();
103 sender_->Send(msg);
106 void Logging::SetIPCSender(IPC::Sender* sender) {
107 sender_ = sender;
110 void Logging::OnReceivedLoggingMessage(const Message& message) {
111 std::vector<LogData> data;
112 PickleIterator iter(message);
113 if (!ReadParam(&message, &iter, &data))
114 return;
116 for (size_t i = 0; i < data.size(); ++i) {
117 Log(data[i]);
121 void Logging::OnSendMessage(Message* message, const std::string& channel_id) {
122 if (!Enabled())
123 return;
125 if (message->is_reply()) {
126 LogData* data = message->sync_log_data();
127 if (!data)
128 return;
130 // This is actually the delayed reply to a sync message. Create a string
131 // of the output parameters, add it to the LogData that was earlier stashed
132 // with the reply, and log the result.
133 GenerateLogData("", *message, data, true);
134 data->channel = channel_id;
135 Log(*data);
136 delete data;
137 message->set_sync_log_data(NULL);
138 } else {
139 // If the time has already been set (i.e. by ChannelProxy), keep that time
140 // instead as it's more accurate.
141 if (!message->sent_time())
142 message->set_sent_time(Time::Now().ToInternalValue());
146 void Logging::OnPreDispatchMessage(const Message& message) {
147 message.set_received_time(Time::Now().ToInternalValue());
150 void Logging::OnPostDispatchMessage(const Message& message,
151 const std::string& channel_id) {
152 if (!Enabled() ||
153 !message.sent_time() ||
154 !message.received_time() ||
155 message.dont_log())
156 return;
158 LogData data;
159 GenerateLogData(channel_id, message, &data, true);
161 if (base::MessageLoop::current() == main_thread_) {
162 Log(data);
163 } else {
164 main_thread_->PostTask(
165 FROM_HERE, base::Bind(&Logging::Log, base::Unretained(this), data));
169 void Logging::GetMessageText(uint32 type, std::string* name,
170 const Message* message,
171 std::string* params) {
172 if (!log_function_map_)
173 return;
175 LogFunctionMap::iterator it = log_function_map_->find(type);
176 if (it == log_function_map_->end()) {
177 if (name) {
178 *name = "[UNKNOWN MSG ";
179 *name += base::IntToString(type);
180 *name += " ]";
182 return;
185 (*it->second)(name, message, params);
188 const char* Logging::ANSIEscape(ANSIColor color) {
189 if (!enabled_color_)
190 return "";
191 switch (color) {
192 case ANSI_COLOR_RESET:
193 return "\033[m";
194 case ANSI_COLOR_BLACK:
195 return "\033[0;30m";
196 case ANSI_COLOR_RED:
197 return "\033[0;31m";
198 case ANSI_COLOR_GREEN:
199 return "\033[0;32m";
200 case ANSI_COLOR_YELLOW:
201 return "\033[0;33m";
202 case ANSI_COLOR_BLUE:
203 return "\033[0;34m";
204 case ANSI_COLOR_MAGENTA:
205 return "\033[0;35m";
206 case ANSI_COLOR_CYAN:
207 return "\033[0;36m";
208 case ANSI_COLOR_WHITE:
209 return "\033[0;37m";
211 return "";
214 Logging::ANSIColor Logging::DelayColor(double delay) {
215 if (delay < 0.1)
216 return ANSI_COLOR_GREEN;
217 if (delay < 0.25)
218 return ANSI_COLOR_BLACK;
219 if (delay < 0.5)
220 return ANSI_COLOR_YELLOW;
221 return ANSI_COLOR_RED;
224 void Logging::Log(const LogData& data) {
225 if (consumer_) {
226 // We're in the browser process.
227 consumer_->Log(data);
228 } else {
229 // We're in the renderer or plugin processes.
230 if (sender_) {
231 queued_logs_.push_back(data);
232 if (!queue_invoke_later_pending_) {
233 queue_invoke_later_pending_ = true;
234 base::MessageLoop::current()->PostDelayedTask(
235 FROM_HERE,
236 base::Bind(&Logging::OnSendLogs, base::Unretained(this)),
237 base::TimeDelta::FromMilliseconds(kLogSendDelayMs));
241 if (enabled_on_stderr_) {
242 std::string message_name;
243 if (data.message_name.empty()) {
244 message_name = base::StringPrintf("[unknown type %d]", data.type);
245 } else {
246 message_name = data.message_name;
248 double receive_delay =
249 (Time::FromInternalValue(data.receive) -
250 Time::FromInternalValue(data.sent)).InSecondsF();
251 double dispatch_delay =
252 (Time::FromInternalValue(data.dispatch) -
253 Time::FromInternalValue(data.sent)).InSecondsF();
254 fprintf(stderr,
255 "ipc %s %d %s %s%s %s%s\n %18.5f %s%18.5f %s%18.5f%s\n",
256 data.channel.c_str(),
257 data.routing_id,
258 data.flags.c_str(),
259 ANSIEscape(sender_ ? ANSI_COLOR_BLUE : ANSI_COLOR_CYAN),
260 message_name.c_str(),
261 ANSIEscape(ANSI_COLOR_RESET),
262 data.params.c_str(),
263 Time::FromInternalValue(data.sent).ToDoubleT(),
264 ANSIEscape(DelayColor(receive_delay)),
265 Time::FromInternalValue(data.receive).ToDoubleT(),
266 ANSIEscape(DelayColor(dispatch_delay)),
267 Time::FromInternalValue(data.dispatch).ToDoubleT(),
268 ANSIEscape(ANSI_COLOR_RESET)
273 void GenerateLogData(const std::string& channel, const Message& message,
274 LogData* data, bool get_params) {
275 if (message.is_reply()) {
276 // "data" should already be filled in.
277 std::string params;
278 Logging::GetMessageText(data->type, NULL, &message, &params);
280 if (!data->params.empty() && !params.empty())
281 data->params += ", ";
283 data->flags += " DR";
285 data->params += params;
286 } else {
287 std::string flags;
288 if (message.is_sync())
289 flags = "S";
291 if (message.is_reply())
292 flags += "R";
294 if (message.is_reply_error())
295 flags += "E";
297 std::string params, message_name;
298 Logging::GetMessageText(message.type(), &message_name, &message,
299 get_params ? &params : NULL);
301 data->channel = channel;
302 data->routing_id = message.routing_id();
303 data->type = message.type();
304 data->flags = flags;
305 data->sent = message.sent_time();
306 data->receive = message.received_time();
307 data->dispatch = Time::Now().ToInternalValue();
308 data->params = params;
309 data->message_name = message_name;
315 #endif // IPC_MESSAGE_LOG_ENABLED