| 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 |