Updating SecurityKeyAuthHandlerPosix socket lifetime management

remoting/host/security_key/security_key_auth_handler_posix.cc

 // Copyright 2016 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "remoting/host/security_key/security_key_auth_handler.h"
 
 #include <unistd.h>
 
 #include <cstdint>
 #include <map>
@@ skipping 25 matching lines @@
 const int64_t kDefaultRequestTimeoutSeconds = 60;
 
 // The name of the socket to listen for security key requests on.
 base::LazyInstance<base::FilePath>::Leaky g_security_key_socket_name =
     LAZY_INSTANCE_INITIALIZER;
 
 // Socket authentication function that only allows connections from callers with
 // the current uid.
 bool MatchUid(const net::UnixDomainServerSocket::Credentials& credentials) {
   bool allowed = credentials.user_id == getuid();
-  if (!allowed)
+  if (!allowed) {
     HOST_LOG << "Refused socket connection from uid " << credentials.user_id;
+  }
   return allowed;
 }
 
 // Returns the command code (the first byte of the data) if it exists, or -1 if
 // the data is empty.
 unsigned int GetCommandCode(const std::string& data) {
   return data.empty() ? -1 : static_cast<unsigned int>(data[0]);
 }
 
 }  // namespace
@@ skipping 136 matching lines @@
 
 bool SecurityKeyAuthHandlerPosix::IsValidConnectionId(int connection_id) const {
   return GetSocketForConnectionId(connection_id) != active_sockets_.end();
 }
 
 void SecurityKeyAuthHandlerPosix::SendClientResponse(
     int connection_id,
     const std::string& response) {
   ActiveSockets::const_iterator iter = GetSocketForConnectionId(connection_id);
   if (iter != active_sockets_.end()) {
+    HOST_LOG << "Sending client response to socket: " << connection_id;

[Sergey Ulanov, 2016/12/19 23:19:18]

Do we really need to log for every Gnubby connection?

[joedow, 2016/12/20 00:28:00]

There shouldn't be too much debug spew but I'll update it to a DLOG.

     iter->second->SendResponse(response);
+    iter->second->StartReadingRequest(
+        base::Bind(&SecurityKeyAuthHandlerPosix::OnReadComplete,
+                   base::Unretained(this), connection_id));
   } else {
     LOG(WARNING) << "Unknown gnubby-auth connection id: " << connection_id;
   }
 }
 
 void SecurityKeyAuthHandlerPosix::SendErrorAndCloseConnection(int id) {
   ActiveSockets::const_iterator iter = GetSocketForConnectionId(id);
   if (iter != active_sockets_.end()) {
-    HOST_LOG << "Sending security key error";
+    HOST_LOG << "Sending error and closing socket: " << id;
     SendErrorAndCloseActiveSocket(iter);
   } else {
     LOG(WARNING) << "Unknown gnubby-auth connection id: " << id;
   }
 }
 
 void SecurityKeyAuthHandlerPosix::SetSendMessageCallback(
     const SendMessageCallback& callback) {
   send_message_callback_ = callback;
 }
@@ skipping 15 matching lines @@
   if (result != net::ERR_IO_PENDING) {
     OnAccepted(result);
   }
 }
 
 void SecurityKeyAuthHandlerPosix::OnAccepted(int result) {
   DCHECK(thread_checker_.CalledOnValidThread());
   DCHECK_NE(net::ERR_IO_PENDING, result);
 
   if (result < 0) {
-    LOG(ERROR) << "Error in accepting a new connection";
+    LOG(ERROR) << "Error accepting new socket connection: " << result;
     return;
   }
 
   int security_key_connection_id = ++last_connection_id_;
+  HOST_LOG << "Creating new socket: " << security_key_connection_id;
   SecurityKeySocket* socket = new SecurityKeySocket(
       std::move(accept_socket_), request_timeout_,
       base::Bind(&SecurityKeyAuthHandlerPosix::RequestTimedOut,
                  base::Unretained(this), security_key_connection_id));
   active_sockets_[security_key_connection_id] = base::WrapUnique(socket);
   socket->StartReadingRequest(
       base::Bind(&SecurityKeyAuthHandlerPosix::OnReadComplete,
                  base::Unretained(this), security_key_connection_id));
 
   // Continue accepting new connections.
   DoAccept();
 }
 
 void SecurityKeyAuthHandlerPosix::OnReadComplete(int connection_id) {
   DCHECK(thread_checker_.CalledOnValidThread());
 
   ActiveSockets::const_iterator iter = active_sockets_.find(connection_id);
   DCHECK(iter != active_sockets_.end());
   std::string request_data;
   if (!iter->second->GetAndClearRequestData(&request_data)) {
-    SendErrorAndCloseActiveSocket(iter);
+    HOST_LOG << "Closing socket: " << connection_id;

[Sergey Ulanov, 2016/12/19 23:19:18]

Log only in case of an error?

[joedow, 2016/12/20 00:28:00]

Updating to DLOG

+    if (iter->second->socket_read_error()) {
+      iter->second->SendSshError();
+    }
+    active_sockets_.erase(iter);
     return;
   }
 
-  HOST_LOG << "Received security key request: " << GetCommandCode(request_data);
+  HOST_LOG << "Received request from socket: " << connection_id
+           << ", code: " << GetCommandCode(request_data);
   send_message_callback_.Run(connection_id, request_data);
-
-  iter->second->StartReadingRequest(
-      base::Bind(&SecurityKeyAuthHandlerPosix::OnReadComplete,
-                 base::Unretained(this), connection_id));
 }
 
 SecurityKeyAuthHandlerPosix::ActiveSockets::const_iterator
 SecurityKeyAuthHandlerPosix::GetSocketForConnectionId(int connection_id) const {
   return active_sockets_.find(connection_id);
 }
 
 void SecurityKeyAuthHandlerPosix::SendErrorAndCloseActiveSocket(
     const ActiveSockets::const_iterator& iter) {
   iter->second->SendSshError();
   active_sockets_.erase(iter);
 }
 
 void SecurityKeyAuthHandlerPosix::RequestTimedOut(int connection_id) {
-  HOST_LOG << "SecurityKey request timed out: " << connection_id;
+  HOST_LOG << "SecurityKey request timed out for socket: " << connection_id;
   ActiveSockets::const_iterator iter = active_sockets_.find(connection_id);
   if (iter != active_sockets_.end()) {
     SendErrorAndCloseActiveSocket(iter);
   }
 }
 
 }  // namespace remoting