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.
4
5#include "chrome/test/chromedriver/chrome/devtools_client_impl.h"
6
7#include "base/bind.h"
8#include "base/json/json_reader.h"
9#include "base/json/json_writer.h"
10#include "base/logging.h"
11#include "base/strings/stringprintf.h"
12#include "base/values.h"
13#include "chrome/test/chromedriver/chrome/devtools_event_listener.h"
14#include "chrome/test/chromedriver/chrome/log.h"
15#include "chrome/test/chromedriver/chrome/status.h"
16#include "chrome/test/chromedriver/chrome/util.h"
17#include "chrome/test/chromedriver/net/sync_websocket.h"
18#include "chrome/test/chromedriver/net/url_request_context_getter.h"
19
20namespace {
21
22const char* kInspectorContextError =
23    "Execution context with given id not found.";
24
25Status ParseInspectorError(const std::string& error_json) {
26  scoped_ptr<base::Value> error(base::JSONReader::Read(error_json));
27  base::DictionaryValue* error_dict;
28  if (!error || !error->GetAsDictionary(&error_dict))
29    return Status(kUnknownError, "inspector error with no error message");
30  std::string error_message;
31  if (error_dict->GetString("message", &error_message) &&
32      error_message == kInspectorContextError) {
33    return Status(kNoSuchExecutionContext);
34  }
35  return Status(kUnknownError, "unhandled inspector error: " + error_json);
36}
37
38class ScopedIncrementer {
39 public:
40  explicit ScopedIncrementer(int* count) : count_(count) {
41    (*count_)++;
42  }
43  ~ScopedIncrementer() {
44    (*count_)--;
45  }
46
47 private:
48  int* count_;
49};
50
51Status ConditionIsMet(bool* is_condition_met) {
52  *is_condition_met = true;
53  return Status(kOk);
54}
55
56}  // namespace
57
58namespace internal {
59
60InspectorEvent::InspectorEvent() {}
61
62InspectorEvent::~InspectorEvent() {}
63
64InspectorCommandResponse::InspectorCommandResponse() {}
65
66InspectorCommandResponse::~InspectorCommandResponse() {}
67
68}  // namespace internal
69
70DevToolsClientImpl::DevToolsClientImpl(
71    const SyncWebSocketFactory& factory,
72    const std::string& url,
73    const std::string& id,
74    const FrontendCloserFunc& frontend_closer_func)
75    : socket_(factory.Run().Pass()),
76      url_(url),
77      crashed_(false),
78      id_(id),
79      frontend_closer_func_(frontend_closer_func),
80      parser_func_(base::Bind(&internal::ParseInspectorMessage)),
81      unnotified_event_(NULL),
82      next_id_(1),
83      stack_count_(0) {}
84
85DevToolsClientImpl::DevToolsClientImpl(
86    const SyncWebSocketFactory& factory,
87    const std::string& url,
88    const std::string& id,
89    const FrontendCloserFunc& frontend_closer_func,
90    const ParserFunc& parser_func)
91    : socket_(factory.Run().Pass()),
92      url_(url),
93      crashed_(false),
94      id_(id),
95      frontend_closer_func_(frontend_closer_func),
96      parser_func_(parser_func),
97      unnotified_event_(NULL),
98      next_id_(1),
99      stack_count_(0) {}
100
101DevToolsClientImpl::~DevToolsClientImpl() {}
102
103void DevToolsClientImpl::SetParserFuncForTesting(
104    const ParserFunc& parser_func) {
105  parser_func_ = parser_func;
106}
107
108const std::string& DevToolsClientImpl::GetId() {
109  return id_;
110}
111
112bool DevToolsClientImpl::WasCrashed() {
113  return crashed_;
114}
115
116Status DevToolsClientImpl::ConnectIfNecessary() {
117  if (stack_count_)
118    return Status(kUnknownError, "cannot connect when nested");
119
120  if (socket_->IsConnected())
121    return Status(kOk);
122
123  if (!socket_->Connect(url_)) {
124    // Try to close devtools frontend and then reconnect.
125    Status status = frontend_closer_func_.Run();
126    if (status.IsError())
127      return status;
128    if (!socket_->Connect(url_))
129      return Status(kDisconnected, "unable to connect to renderer");
130  }
131
132  unnotified_connect_listeners_ = listeners_;
133  unnotified_event_listeners_.clear();
134  response_info_map_.clear();
135
136  // Notify all listeners of the new connection. Do this now so that any errors
137  // that occur are reported now instead of later during some unrelated call.
138  // Also gives listeners a chance to send commands before other clients.
139  return EnsureListenersNotifiedOfConnect();
140}
141
142Status DevToolsClientImpl::SendCommand(
143    const std::string& method,
144    const base::DictionaryValue& params) {
145  scoped_ptr<base::DictionaryValue> result;
146  return SendCommandInternal(method, params, &result);
147}
148
149Status DevToolsClientImpl::SendCommandAndGetResult(
150    const std::string& method,
151    const base::DictionaryValue& params,
152    scoped_ptr<base::DictionaryValue>* result) {
153  scoped_ptr<base::DictionaryValue> intermediate_result;
154  Status status = SendCommandInternal(method, params, &intermediate_result);
155  if (status.IsError())
156    return status;
157  if (!intermediate_result)
158    return Status(kUnknownError, "inspector response missing result");
159  result->reset(intermediate_result.release());
160  return Status(kOk);
161}
162
163void DevToolsClientImpl::AddListener(DevToolsEventListener* listener) {
164  CHECK(listener);
165  listeners_.push_back(listener);
166}
167
168Status DevToolsClientImpl::HandleReceivedEvents() {
169  return HandleEventsUntil(base::Bind(&ConditionIsMet), base::TimeDelta());
170}
171
172Status DevToolsClientImpl::HandleEventsUntil(
173    const ConditionalFunc& conditional_func, const base::TimeDelta& timeout) {
174  if (!socket_->IsConnected())
175    return Status(kDisconnected, "not connected to DevTools");
176
177  base::TimeTicks deadline = base::TimeTicks::Now() + timeout;
178  base::TimeDelta next_message_timeout = timeout;
179  while (true) {
180    if (!socket_->HasNextMessage()) {
181      bool is_condition_met = false;
182      Status status = conditional_func.Run(&is_condition_met);
183      if (status.IsError())
184        return status;
185      if (is_condition_met)
186        return Status(kOk);
187    }
188
189    Status status = ProcessNextMessage(-1, next_message_timeout);
190    if (status.IsError())
191      return status;
192    next_message_timeout = deadline - base::TimeTicks::Now();
193  }
194}
195
196DevToolsClientImpl::ResponseInfo::ResponseInfo(const std::string& method)
197    : state(kWaiting), method(method) {}
198
199DevToolsClientImpl::ResponseInfo::~ResponseInfo() {}
200
201Status DevToolsClientImpl::SendCommandInternal(
202    const std::string& method,
203    const base::DictionaryValue& params,
204    scoped_ptr<base::DictionaryValue>* result) {
205  if (!socket_->IsConnected())
206    return Status(kDisconnected, "not connected to DevTools");
207
208  int command_id = next_id_++;
209  base::DictionaryValue command;
210  command.SetInteger("id", command_id);
211  command.SetString("method", method);
212  command.Set("params", params.DeepCopy());
213  std::string message = SerializeValue(&command);
214  if (IsVLogOn(1)) {
215    VLOG(1) << "DEVTOOLS COMMAND " << method << " (id=" << command_id << ") "
216            << FormatValueForDisplay(params);
217  }
218  if (!socket_->Send(message))
219    return Status(kDisconnected, "unable to send message to renderer");
220
221  linked_ptr<ResponseInfo> response_info =
222      make_linked_ptr(new ResponseInfo(method));
223  response_info_map_[command_id] = response_info;
224  while (response_info->state == kWaiting) {
225    Status status = ProcessNextMessage(
226        command_id, base::TimeDelta::FromMinutes(10));
227    if (status.IsError()) {
228      if (response_info->state == kReceived)
229        response_info_map_.erase(command_id);
230      return status;
231    }
232  }
233  if (response_info->state == kBlocked) {
234    response_info->state = kIgnored;
235    return Status(kUnexpectedAlertOpen);
236  }
237  CHECK_EQ(response_info->state, kReceived);
238  internal::InspectorCommandResponse& response = response_info->response;
239  if (!response.result)
240    return ParseInspectorError(response.error);
241  *result = response.result.Pass();
242  return Status(kOk);
243}
244
245Status DevToolsClientImpl::ProcessNextMessage(
246    int expected_id,
247    const base::TimeDelta& timeout) {
248  ScopedIncrementer increment_stack_count(&stack_count_);
249
250  Status status = EnsureListenersNotifiedOfConnect();
251  if (status.IsError())
252    return status;
253  status = EnsureListenersNotifiedOfEvent();
254  if (status.IsError())
255    return status;
256  status = EnsureListenersNotifiedOfCommandResponse();
257  if (status.IsError())
258    return status;
259
260  // The command response may have already been received or blocked while
261  // notifying listeners.
262  if (expected_id != -1 && response_info_map_[expected_id]->state != kWaiting)
263    return Status(kOk);
264
265  if (crashed_)
266    return Status(kTabCrashed);
267
268  std::string message;
269  switch (socket_->ReceiveNextMessage(&message, timeout)) {
270    case SyncWebSocket::kOk:
271      break;
272    case SyncWebSocket::kDisconnected: {
273      std::string err = "Unable to receive message from renderer";
274      LOG(ERROR) << err;
275      return Status(kDisconnected, err);
276    }
277    case SyncWebSocket::kTimeout: {
278      std::string err =
279          "Timed out receiving message from renderer: " +
280          base::StringPrintf("%.3lf", timeout.InSecondsF());
281      LOG(ERROR) << err;
282      return Status(kTimeout, err);
283    }
284    default:
285      NOTREACHED();
286      break;
287  }
288
289  internal::InspectorMessageType type;
290  internal::InspectorEvent event;
291  internal::InspectorCommandResponse response;
292  if (!parser_func_.Run(message, expected_id, &type, &event, &response)) {
293    LOG(ERROR) << "Bad inspector message: " << message;
294    return Status(kUnknownError, "bad inspector message: " + message);
295  }
296
297  if (type == internal::kEventMessageType)
298    return ProcessEvent(event);
299  CHECK_EQ(type, internal::kCommandResponseMessageType);
300  return ProcessCommandResponse(response);
301}
302
303Status DevToolsClientImpl::ProcessEvent(const internal::InspectorEvent& event) {
304  if (IsVLogOn(1)) {
305    VLOG(1) << "DEVTOOLS EVENT " << event.method << " "
306            << FormatValueForDisplay(*event.params);
307  }
308  unnotified_event_listeners_ = listeners_;
309  unnotified_event_ = &event;
310  Status status = EnsureListenersNotifiedOfEvent();
311  unnotified_event_ = NULL;
312  if (status.IsError())
313    return status;
314  if (event.method == "Inspector.detached")
315    return Status(kDisconnected, "received Inspector.detached event");
316  if (event.method == "Inspector.targetCrashed") {
317    crashed_ = true;
318    return Status(kTabCrashed);
319  }
320  if (event.method == "Page.javascriptDialogOpening") {
321    // A command may have opened the dialog, which will block the response.
322    // To find out which one (if any), do a round trip with a simple command
323    // to the renderer and afterwards see if any of the commands still haven't
324    // received a response.
325    // This relies on the fact that DevTools commands are processed
326    // sequentially. This may break if any of the commands are asynchronous.
327    // If for some reason the round trip command fails, mark all the waiting
328    // commands as blocked and return the error. This is better than risking
329    // a hang.
330    int max_id = next_id_;
331    base::DictionaryValue enable_params;
332    enable_params.SetString("purpose", "detect if alert blocked any cmds");
333    Status enable_status = SendCommand("Inspector.enable", enable_params);
334    for (ResponseInfoMap::const_iterator iter = response_info_map_.begin();
335         iter != response_info_map_.end(); ++iter) {
336      if (iter->first > max_id)
337        continue;
338      if (iter->second->state == kWaiting)
339        iter->second->state = kBlocked;
340    }
341    if (enable_status.IsError())
342      return status;
343  }
344  return Status(kOk);
345}
346
347Status DevToolsClientImpl::ProcessCommandResponse(
348    const internal::InspectorCommandResponse& response) {
349  ResponseInfoMap::iterator iter = response_info_map_.find(response.id);
350  if (IsVLogOn(1)) {
351    std::string method, result;
352    if (iter != response_info_map_.end())
353      method = iter->second->method;
354    if (response.result)
355      result = FormatValueForDisplay(*response.result);
356    else
357      result = response.error;
358    VLOG(1) << "DEVTOOLS RESPONSE " << method << " (id=" << response.id
359            << ") " << result;
360  }
361
362  if (iter == response_info_map_.end())
363    return Status(kUnknownError, "unexpected command response");
364
365  linked_ptr<ResponseInfo> response_info = response_info_map_[response.id];
366  if (response_info->state == kReceived)
367    return Status(kUnknownError, "received multiple command responses");
368
369  if (response_info->state == kIgnored) {
370    response_info_map_.erase(response.id);
371  } else {
372    response_info->state = kReceived;
373    response_info->response.id = response.id;
374    response_info->response.error = response.error;
375    if (response.result)
376      response_info->response.result.reset(response.result->DeepCopy());
377  }
378
379  if (response.result) {
380    unnotified_cmd_response_listeners_ = listeners_;
381    unnotified_cmd_response_info_ = response_info;
382    Status status = EnsureListenersNotifiedOfCommandResponse();
383    unnotified_cmd_response_info_.reset();
384    if (status.IsError())
385      return status;
386  }
387  return Status(kOk);
388}
389
390Status DevToolsClientImpl::EnsureListenersNotifiedOfConnect() {
391  while (unnotified_connect_listeners_.size()) {
392    DevToolsEventListener* listener = unnotified_connect_listeners_.front();
393    unnotified_connect_listeners_.pop_front();
394    Status status = listener->OnConnected(this);
395    if (status.IsError())
396      return status;
397  }
398  return Status(kOk);
399}
400
401Status DevToolsClientImpl::EnsureListenersNotifiedOfEvent() {
402  while (unnotified_event_listeners_.size()) {
403    DevToolsEventListener* listener = unnotified_event_listeners_.front();
404    unnotified_event_listeners_.pop_front();
405    Status status = listener->OnEvent(
406        this, unnotified_event_->method, *unnotified_event_->params);
407    if (status.IsError())
408      return status;
409  }
410  return Status(kOk);
411}
412
413Status DevToolsClientImpl::EnsureListenersNotifiedOfCommandResponse() {
414  while (unnotified_cmd_response_listeners_.size()) {
415    DevToolsEventListener* listener =
416        unnotified_cmd_response_listeners_.front();
417    unnotified_cmd_response_listeners_.pop_front();
418    Status status =
419        listener->OnCommandSuccess(this, unnotified_cmd_response_info_->method);
420    if (status.IsError())
421      return status;
422  }
423  return Status(kOk);
424}
425
426namespace internal {
427
428bool ParseInspectorMessage(
429    const std::string& message,
430    int expected_id,
431    InspectorMessageType* type,
432    InspectorEvent* event,
433    InspectorCommandResponse* command_response) {
434  scoped_ptr<base::Value> message_value(base::JSONReader::Read(message));
435  base::DictionaryValue* message_dict;
436  if (!message_value || !message_value->GetAsDictionary(&message_dict))
437    return false;
438
439  int id;
440  if (!message_dict->HasKey("id")) {
441    std::string method;
442    if (!message_dict->GetString("method", &method))
443      return false;
444    base::DictionaryValue* params = NULL;
445    message_dict->GetDictionary("params", &params);
446
447    *type = kEventMessageType;
448    event->method = method;
449    if (params)
450      event->params.reset(params->DeepCopy());
451    else
452      event->params.reset(new base::DictionaryValue());
453    return true;
454  } else if (message_dict->GetInteger("id", &id)) {
455    base::DictionaryValue* unscoped_error = NULL;
456    base::DictionaryValue* unscoped_result = NULL;
457    if (!message_dict->GetDictionary("error", &unscoped_error) &&
458        !message_dict->GetDictionary("result", &unscoped_result))
459      return false;
460
461    *type = kCommandResponseMessageType;
462    command_response->id = id;
463    if (unscoped_result)
464      command_response->result.reset(unscoped_result->DeepCopy());
465    else
466      base::JSONWriter::Write(unscoped_error, &command_response->error);
467    return true;
468  }
469  return false;
470}
471
472}  // namespace internal
473