OLD | NEW |
1 // Copyright (c) 2012 The Chromium Authors. All rights reserved. | 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 | 2 // Use of this source code is governed by a BSD-style license that can be |
3 // found in the LICENSE file. | 3 // found in the LICENSE file. |
4 | 4 |
5 #include "ipc/ipc_logging.h" | 5 #include "ipc/ipc_logging.h" |
6 | 6 |
7 #ifdef IPC_MESSAGE_LOG_ENABLED | 7 #ifdef IPC_MESSAGE_LOG_ENABLED |
8 #define IPC_MESSAGE_MACROS_LOG_ENABLED | 8 #define IPC_MESSAGE_MACROS_LOG_ENABLED |
9 #endif | 9 #endif |
10 | 10 |
(...skipping 104 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
115 std::vector<LogData> data; | 115 std::vector<LogData> data; |
116 base::PickleIterator iter(message); | 116 base::PickleIterator iter(message); |
117 if (!ReadParam(&message, &iter, &data)) | 117 if (!ReadParam(&message, &iter, &data)) |
118 return; | 118 return; |
119 | 119 |
120 for (size_t i = 0; i < data.size(); ++i) { | 120 for (size_t i = 0; i < data.size(); ++i) { |
121 Log(data[i]); | 121 Log(data[i]); |
122 } | 122 } |
123 } | 123 } |
124 | 124 |
125 void Logging::OnSendMessage(Message* message, const std::string& channel_id) { | 125 void Logging::OnSendMessage(Message* message) { |
126 if (!Enabled()) | 126 if (!Enabled()) |
127 return; | 127 return; |
128 | 128 |
129 if (message->is_reply()) { | 129 if (message->is_reply()) { |
130 LogData* data = message->sync_log_data(); | 130 LogData* data = message->sync_log_data(); |
131 if (!data) | 131 if (!data) |
132 return; | 132 return; |
133 | 133 |
134 // This is actually the delayed reply to a sync message. Create a string | 134 // This is actually the delayed reply to a sync message. Create a string |
135 // of the output parameters, add it to the LogData that was earlier stashed | 135 // of the output parameters, add it to the LogData that was earlier stashed |
136 // with the reply, and log the result. | 136 // with the reply, and log the result. |
137 GenerateLogData("", *message, data, true); | 137 GenerateLogData(*message, data, true); |
138 data->channel = channel_id; | |
139 Log(*data); | 138 Log(*data); |
140 delete data; | 139 delete data; |
141 message->set_sync_log_data(NULL); | 140 message->set_sync_log_data(NULL); |
142 } else { | 141 } else { |
143 // If the time has already been set (i.e. by ChannelProxy), keep that time | 142 // If the time has already been set (i.e. by ChannelProxy), keep that time |
144 // instead as it's more accurate. | 143 // instead as it's more accurate. |
145 if (!message->sent_time()) | 144 if (!message->sent_time()) |
146 message->set_sent_time(Time::Now().ToInternalValue()); | 145 message->set_sent_time(Time::Now().ToInternalValue()); |
147 } | 146 } |
148 } | 147 } |
149 | 148 |
150 void Logging::OnPreDispatchMessage(const Message& message) { | 149 void Logging::OnPreDispatchMessage(const Message& message) { |
151 message.set_received_time(Time::Now().ToInternalValue()); | 150 message.set_received_time(Time::Now().ToInternalValue()); |
152 } | 151 } |
153 | 152 |
154 void Logging::OnPostDispatchMessage(const Message& message, | 153 void Logging::OnPostDispatchMessage(const Message& message) { |
155 const std::string& channel_id) { | |
156 if (!Enabled() || | 154 if (!Enabled() || |
157 !message.sent_time() || | 155 !message.sent_time() || |
158 !message.received_time() || | 156 !message.received_time() || |
159 message.dont_log()) | 157 message.dont_log()) |
160 return; | 158 return; |
161 | 159 |
162 LogData data; | 160 LogData data; |
163 GenerateLogData(channel_id, message, &data, true); | 161 GenerateLogData(message, &data, true); |
164 | 162 |
165 if (main_thread_->BelongsToCurrentThread()) { | 163 if (main_thread_->BelongsToCurrentThread()) { |
166 Log(data); | 164 Log(data); |
167 } else { | 165 } else { |
168 main_thread_->PostTask( | 166 main_thread_->PostTask( |
169 FROM_HERE, base::Bind(&Logging::Log, base::Unretained(this), data)); | 167 FROM_HERE, base::Bind(&Logging::Log, base::Unretained(this), data)); |
170 } | 168 } |
171 } | 169 } |
172 | 170 |
173 void Logging::GetMessageText(uint32_t type, std::string* name, | 171 void Logging::GetMessageText(uint32_t type, std::string* name, |
(...skipping 74 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
248 } else { | 246 } else { |
249 message_name = data.message_name; | 247 message_name = data.message_name; |
250 } | 248 } |
251 double receive_delay = | 249 double receive_delay = |
252 (Time::FromInternalValue(data.receive) - | 250 (Time::FromInternalValue(data.receive) - |
253 Time::FromInternalValue(data.sent)).InSecondsF(); | 251 Time::FromInternalValue(data.sent)).InSecondsF(); |
254 double dispatch_delay = | 252 double dispatch_delay = |
255 (Time::FromInternalValue(data.dispatch) - | 253 (Time::FromInternalValue(data.dispatch) - |
256 Time::FromInternalValue(data.sent)).InSecondsF(); | 254 Time::FromInternalValue(data.sent)).InSecondsF(); |
257 fprintf(stderr, | 255 fprintf(stderr, |
258 "ipc %s %d %s %s%s %s%s\n %18.5f %s%18.5f %s%18.5f%s\n", | 256 "ipc %d %s %s%s %s%s\n %18.5f %s%18.5f %s%18.5f%s\n", |
259 data.channel.c_str(), | |
260 data.routing_id, | 257 data.routing_id, |
261 data.flags.c_str(), | 258 data.flags.c_str(), |
262 ANSIEscape(sender_ ? ANSI_COLOR_BLUE : ANSI_COLOR_CYAN), | 259 ANSIEscape(sender_ ? ANSI_COLOR_BLUE : ANSI_COLOR_CYAN), |
263 message_name.c_str(), | 260 message_name.c_str(), |
264 ANSIEscape(ANSI_COLOR_RESET), | 261 ANSIEscape(ANSI_COLOR_RESET), |
265 data.params.c_str(), | 262 data.params.c_str(), |
266 Time::FromInternalValue(data.sent).ToDoubleT(), | 263 Time::FromInternalValue(data.sent).ToDoubleT(), |
267 ANSIEscape(DelayColor(receive_delay)), | 264 ANSIEscape(DelayColor(receive_delay)), |
268 Time::FromInternalValue(data.receive).ToDoubleT(), | 265 Time::FromInternalValue(data.receive).ToDoubleT(), |
269 ANSIEscape(DelayColor(dispatch_delay)), | 266 ANSIEscape(DelayColor(dispatch_delay)), |
270 Time::FromInternalValue(data.dispatch).ToDoubleT(), | 267 Time::FromInternalValue(data.dispatch).ToDoubleT(), |
271 ANSIEscape(ANSI_COLOR_RESET) | 268 ANSIEscape(ANSI_COLOR_RESET) |
272 ); | 269 ); |
273 } | 270 } |
274 } | 271 } |
275 | 272 |
276 void GenerateLogData(const std::string& channel, const Message& message, | 273 void GenerateLogData(const Message& message, LogData* data, bool get_params) { |
277 LogData* data, bool get_params) { | |
278 if (message.is_reply()) { | 274 if (message.is_reply()) { |
279 // "data" should already be filled in. | 275 // "data" should already be filled in. |
280 std::string params; | 276 std::string params; |
281 Logging::GetMessageText(data->type, NULL, &message, ¶ms); | 277 Logging::GetMessageText(data->type, NULL, &message, ¶ms); |
282 | 278 |
283 if (!data->params.empty() && !params.empty()) | 279 if (!data->params.empty() && !params.empty()) |
284 data->params += ", "; | 280 data->params += ", "; |
285 | 281 |
286 data->flags += " DR"; | 282 data->flags += " DR"; |
287 | 283 |
288 data->params += params; | 284 data->params += params; |
289 } else { | 285 } else { |
290 std::string flags; | 286 std::string flags; |
291 if (message.is_sync()) | 287 if (message.is_sync()) |
292 flags = "S"; | 288 flags = "S"; |
293 | 289 |
294 if (message.is_reply()) | 290 if (message.is_reply()) |
295 flags += "R"; | 291 flags += "R"; |
296 | 292 |
297 if (message.is_reply_error()) | 293 if (message.is_reply_error()) |
298 flags += "E"; | 294 flags += "E"; |
299 | 295 |
300 std::string params, message_name; | 296 std::string params, message_name; |
301 Logging::GetMessageText(message.type(), &message_name, &message, | 297 Logging::GetMessageText(message.type(), &message_name, &message, |
302 get_params ? ¶ms : NULL); | 298 get_params ? ¶ms : NULL); |
303 | 299 |
304 data->channel = channel; | |
305 data->routing_id = message.routing_id(); | 300 data->routing_id = message.routing_id(); |
306 data->type = message.type(); | 301 data->type = message.type(); |
307 data->flags = flags; | 302 data->flags = flags; |
308 data->sent = message.sent_time(); | 303 data->sent = message.sent_time(); |
309 data->receive = message.received_time(); | 304 data->receive = message.received_time(); |
310 data->dispatch = Time::Now().ToInternalValue(); | 305 data->dispatch = Time::Now().ToInternalValue(); |
311 data->params = params; | 306 data->params = params; |
312 data->message_name = message_name; | 307 data->message_name = message_name; |
313 } | 308 } |
314 } | 309 } |
315 | 310 |
316 } | 311 } |
317 | 312 |
318 #endif // IPC_MESSAGE_LOG_ENABLED | 313 #endif // IPC_MESSAGE_LOG_ENABLED |
OLD | NEW |