dbus: Thread assertion and log long blocking calls

- DCHECK -> CHECK in Bus::AssertOnOriginThread/DBusThread to
  enable thread assertion in release build;
- Add warning log if Bus::SendWithReplyAndBlock takes more
  than 1 seconds;

Bug: 883029
Change-Id: Id630ed56e82a24c88c96820cfc36f5b36c72dd00
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1594064Reviewed-by: Ryo Hashimoto <hashimoto@chromium.org>
Commit-Queue: Xiyuan Xia <xiyuan@chromium.org>
Cr-Commit-Position: refs/heads/master@{#657689}

dbus/bus.cc

@@ -19,6 +19,7 @@
 #include "base/threading/thread_restrictions.h"
 #include "base/threading/thread_task_runner_handle.h"
 #include "base/time/time.h"
+#include "base/timer/elapsed_timer.h"
 #include "dbus/exported_object.h"
 #include "dbus/message.h"
 #include "dbus/object_manager.h"
@@ -625,10 +626,23 @@ DBusMessage* Bus::SendWithReplyAndBlock(DBusMessage* request,
   DCHECK(connection_);
   AssertOnDBusThread();
 
+  base::ElapsedTimer elapsed;
+
   base::ScopedBlockingCall scoped_blocking_call(FROM_HERE,
                                                 base::BlockingType::MAY_BLOCK);
-  return dbus_connection_send_with_reply_and_block(
+  DBusMessage* reply = dbus_connection_send_with_reply_and_block(
       connection_, request, timeout_ms, error);
+
+  constexpr base::TimeDelta kLongCall = base::TimeDelta::FromSeconds(1);
+  LOG_IF(WARNING, elapsed.Elapsed() >= kLongCall)
+      << "Bus::SendWithReplyAndBlock took "
+      << elapsed.Elapsed().InMilliseconds() << "ms to process message: "
+      << "type=" << dbus_message_type_to_string(dbus_message_get_type(request))
+      << ", path=" << dbus_message_get_path(request)
+      << ", interface=" << dbus_message_get_interface(request)
+      << ", member=" << dbus_message_get_member(request);
+
+  return reply;
 }
 
 void Bus::SendWithReply(DBusMessage* request,
@@ -844,12 +858,12 @@ bool Bus::HasDBusThread() {
 }
 
 void Bus::AssertOnOriginThread() {
-  DCHECK_EQ(origin_thread_id_, base::PlatformThread::CurrentId());
+  CHECK_EQ(origin_thread_id_, base::PlatformThread::CurrentId());
 }
 
 void Bus::AssertOnDBusThread() {
   if (dbus_task_runner_) {
-    DCHECK(dbus_task_runner_->RunsTasksInCurrentSequence());
+    CHECK(dbus_task_runner_->RunsTasksInCurrentSequence());
   } else {
     AssertOnOriginThread();
   }