Improve warning on long RawConnection::flush.

td/mtproto/RawConnection.cpp

@@ -49,11 +49,13 @@ class RawConnectionDefault final : public RawConnection {
   bool can_send() const final {
     return transport_->can_write();
   }
+
   TransportType get_transport_type() const final {
     return transport_->get_type();
   }
-  void send_crypto(const Storer &storer, int64 session_id, int64 salt, const AuthKey &auth_key,
+
-                   uint64 quick_ack_token) final {
+  size_t send_crypto(const Storer &storer, int64 session_id, int64 salt, const AuthKey &auth_key,
+                     uint64 quick_ack_token) final {
     PacketInfo info;
     info.version = 2;
     info.no_crypto_flag = false;
@@ -76,7 +78,9 @@ class RawConnectionDefault final : public RawConnection {
       }
     }
 
+    auto packet_size = packet.size();
     transport_->write(std::move(packet), use_quick_ack);
+    return packet_size;
   }
 
   uint64 send_no_crypto(const Storer &storer) final {
@@ -280,11 +284,13 @@ class RawConnectionHttp final : public RawConnection {
   bool can_send() const final {
     return mode_ == Send;
   }
+
   TransportType get_transport_type() const final {
     return mtproto::TransportType{mtproto::TransportType::Http, 0, mtproto::ProxySecret()};
   }
-  void send_crypto(const Storer &storer, int64 session_id, int64 salt, const AuthKey &auth_key,
+
-                   uint64 quick_ack_token) final {
+  size_t send_crypto(const Storer &storer, int64 session_id, int64 salt, const AuthKey &auth_key,
+                     uint64 quick_ack_token) final {
     PacketInfo info;
     info.version = 2;
     info.no_crypto_flag = false;
@@ -295,7 +301,9 @@ class RawConnectionHttp final : public RawConnection {
     auto packet = BufferWriter{Transport::write(storer, auth_key, &info), 0, 0};
     Transport::write(storer, auth_key, &info, packet.as_slice());
 
+    auto packet_size = packet.size();
     send_packet(packet.as_buffer_slice());
+    return packet_size;
   }
 
   uint64 send_no_crypto(const Storer &storer) final {

td/mtproto/RawConnection.h

@@ -48,8 +48,8 @@ class RawConnection {
 
   virtual bool can_send() const = 0;
   virtual TransportType get_transport_type() const = 0;
-  virtual void send_crypto(const Storer &storer, int64 session_id, int64 salt, const AuthKey &auth_key,
+  virtual size_t send_crypto(const Storer &storer, int64 session_id, int64 salt, const AuthKey &auth_key,
-                           uint64 quick_ack_token) = 0;
+                             uint64 quick_ack_token) = 0;
   virtual uint64 send_no_crypto(const Storer &storer) = 0;
 
   virtual PollableFdInfo &get_poll_info() = 0;

td/mtproto/SessionConnection.cpp

@@ -26,7 +26,6 @@
 #include "td/utils/ScopeGuard.h"
 #include "td/utils/SliceBuilder.h"
 #include "td/utils/Time.h"
-#include "td/utils/Timer.h"
 #include "td/utils/tl_parsers.h"
 #include "td/utils/TlDowncastHelper.h"
 
@@ -718,6 +717,7 @@ Status SessionConnection::on_quick_ack(uint64 quick_ack_token) {
 
 void SessionConnection::on_read(size_t size) {
   last_read_at_ = Time::now_cached();
+  last_read_size_ += size;
 }
 
 SessionConnection::SessionConnection(Mode mode, unique_ptr<RawConnection> raw_connection, AuthData *auth_data)
@@ -768,8 +768,9 @@ void SessionConnection::do_close(Status status) {
 
 void SessionConnection::send_crypto(const Storer &storer, uint64 quick_ack_token) {
   CHECK(state_ != Closed);
-  raw_connection_->send_crypto(storer, auth_data_->get_session_id(), auth_data_->get_server_salt(Time::now_cached()),
+  last_write_size_ += raw_connection_->send_crypto(storer, auth_data_->get_session_id(),
-                               auth_data_->get_auth_key(), quick_ack_token);
+                                                   auth_data_->get_server_salt(Time::now_cached()),
+                                                   auth_data_->get_auth_key(), quick_ack_token);
 }
 
 Result<uint64> SessionConnection::send_query(BufferSlice buffer, bool gzip_flag, int64 message_id,
@@ -1028,7 +1029,6 @@ Status SessionConnection::do_flush() {
                              << connected_flag_ << ' ' << is_main_ << ' ' << need_destroy_auth_key_ << ' '
                              << sent_destroy_auth_key_ << ' ' << callback_ << ' ' << (Time::now() - created_at_) << ' '
                              << (Time::now() - last_read_at_);
-  PerfWarningTimer timer("SessionConnection::do_flush", 0.01);
   CHECK(state_ != Closed);
   if (state_ == Init) {
     TRY_STATUS(init());
@@ -1037,7 +1037,18 @@ Status SessionConnection::do_flush() {
     return Status::Error("No auth key");
   }
 
-  TRY_STATUS(raw_connection_->flush(auth_data_->get_auth_key(), *this));
+  last_read_size_ = 0;
+  last_write_size_ = 0;
+  auto start_time = Time::now();
+  auto result = raw_connection_->flush(auth_data_->get_auth_key(), *this);
+  auto elapsed_time = Time::now() - start_time;
+  if (elapsed_time >= 0.01) {
+    LOG(ERROR) << "RawConnection::flush took " << elapsed_time << " seconds, written " << last_write_size_
+               << " bytes, read " << last_read_size_ << " bytes and returned " << result;
+  }
+  if (result.is_error()) {
+    return result;
+  }
 
   if (last_pong_at_ + ping_disconnect_delay() < Time::now_cached()) {
     auto stats_callback = raw_connection_->stats_callback();

td/mtproto/SessionConnection.h

@@ -189,6 +189,9 @@ class SessionConnection final
   uint64 last_ping_message_id_ = 0;
   uint64 last_ping_container_id_ = 0;
 
+  uint64 last_read_size_ = 0;
+  uint64 last_write_size_ = 0;
+
   bool need_destroy_auth_key_ = false;
   bool sent_destroy_auth_key_ = false;