Add NetLog support to UDP sockets.

net/udp/udp_socket_libevent.cc

 // Copyright (c) 2011 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 "net/udp/udp_socket_libevent.h"
 
 #include <errno.h>
 #include <fcntl.h>
 #include <netdb.h>
 #include <sys/socket.h>
 
 #include "base/eintr_wrapper.h"
 #include "base/logging.h"
 #include "base/message_loop.h"
 #include "base/metrics/stats_counters.h"
 #include "base/rand_util.h"
 #include "net/base/io_buffer.h"
 #include "net/base/ip_endpoint.h"
 #include "net/base/net_errors.h"
 #include "net/base/net_log.h"
 #include "net/base/net_util.h"
+#include "net/udp/udp_data_transfer_param.h"
 #if defined(OS_POSIX)
 #include <netinet/in.h>
 #endif
 
 namespace {
 
 static const int kBindRetries = 10;
 static const int kPortStart = 1024;
 static const int kPortEnd = 65535;
 
 }  // namespace net
 
 namespace net {
 
 UDPSocketLibevent::UDPSocketLibevent(
     DatagramSocket::BindType bind_type,
     const RandIntCallback& rand_int_cb,
     net::NetLog* net_log,
     const net::NetLog::Source& source)
         : socket_(kInvalidSocket),
           bind_type_(bind_type),
           rand_int_cb_(rand_int_cb),
           read_watcher_(this),
           write_watcher_(this),
           read_buf_len_(0),
           recv_from_address_(NULL),
           write_buf_len_(0),
           read_callback_(NULL),
           write_callback_(NULL),
-          net_log_(BoundNetLog::Make(net_log, NetLog::SOURCE_SOCKET)) {
+          net_log_(BoundNetLog::Make(net_log, NetLog::SOURCE_UDP_SOCKET)) {
   scoped_refptr<NetLog::EventParameters> params;
   if (source.is_valid())
     params = new NetLogSourceParameter("source_dependency", source);
   net_log_.BeginEvent(NetLog::TYPE_SOCKET_ALIVE, params);
   if (bind_type == DatagramSocket::RANDOM_BIND)
     DCHECK(!rand_int_cb.is_null());
 }
 
 UDPSocketLibevent::~UDPSocketLibevent() {
   Close();
@@ skipping 82 matching lines @@
                                 IPEndPoint* address,
                                 OldCompletionCallback* callback) {
   DCHECK(CalledOnValidThread());
   DCHECK_NE(kInvalidSocket, socket_);
   DCHECK(!read_callback_);
   DCHECK(!recv_from_address_);
   DCHECK(callback);  // Synchronous operation not supported
   DCHECK_GT(buf_len, 0);
 
   int nread = InternalRecvFrom(buf, buf_len, address);
-  if (nread != ERR_IO_PENDING)
+  if (nread != ERR_IO_PENDING) {
+    if (nread < 0) {

[Sergey Ulanov, 2011/10/14 20:15:47]

nit: remove braces here - they are not used in this file for single-line
statements.

[mmenke, 2011/10/17 17:35:20]

Done.

+      net_log_.AddEventWithNetErrorCode(NetLog::TYPE_UDP_RECEIVE_ERROR, nread);
+    }
     return nread;
+  }
 
   if (!MessageLoopForIO::current()->WatchFileDescriptor(
           socket_, true, MessageLoopForIO::WATCH_READ,
           &read_socket_watcher_, &read_watcher_)) {
     PLOG(ERROR) << "WatchFileDescriptor failed on read";
-    return MapSystemError(errno);
+    int net_error = MapSystemError(errno);
+    net_log_.AddEventWithNetErrorCode(NetLog::TYPE_UDP_RECEIVE_ERROR,
+                                      net_error);
+    return net_error;
   }
 
   read_buf_ = buf;
   read_buf_len_ = buf_len;
   recv_from_address_ = address;
   read_callback_ = callback;
   return ERR_IO_PENDING;
 }
 
 int UDPSocketLibevent::Write(IOBuffer* buf,
@@ skipping 14 matching lines @@
                                      const IPEndPoint* address,
                                      OldCompletionCallback* callback) {
   DCHECK(CalledOnValidThread());
   DCHECK_NE(kInvalidSocket, socket_);
   DCHECK(!write_callback_);
   DCHECK(callback);  // Synchronous operation not supported
   DCHECK_GT(buf_len, 0);
 
   int nwrite = InternalSendTo(buf, buf_len, address);
   if (nwrite >= 0) {
-    base::StatsCounter write_bytes("udp.write_bytes");
-    write_bytes.Add(nwrite);
+    ProcessSuccessfulWrite(nwrite, buf->data(), address);
     return nwrite;
   }
-  if (errno != EAGAIN && errno != EWOULDBLOCK)
-    return MapSystemError(errno);
+  if (errno != EAGAIN && errno != EWOULDBLOCK) {
+    int net_error = MapSystemError(errno);
+    net_log_.AddEventWithNetErrorCode(NetLog::TYPE_UDP_SEND_ERROR,

[Sergey Ulanov, 2011/10/14 20:15:47]

optional nit: This code is duplicated in DidCompleteWrite(). Maybe rename
ProcessSuccessfulWrite() to LogWrite() and just call it here for any result.
same for ProcessSuccessulRead()

[mmenke, 2011/10/17 17:35:20]

Done.  I really like this idea.  Results in a lot less logging code all over the
place.

+                                      net_error);
+    return net_error;
+  }
 
   if (!MessageLoopForIO::current()->WatchFileDescriptor(
           socket_, true, MessageLoopForIO::WATCH_WRITE,
           &write_socket_watcher_, &write_watcher_)) {
     DVLOG(1) << "WatchFileDescriptor failed on write, errno " << errno;
-    return MapSystemError(errno);
+    int net_error = MapSystemError(errno);
+    net_log_.AddEventWithNetErrorCode(NetLog::TYPE_UDP_SEND_ERROR,
+                                      net_error);
+    return net_error;
   }
 
   write_buf_ = buf;
   write_buf_len_ = buf_len;
   DCHECK(!send_to_address_.get());
   if (address) {
     send_to_address_.reset(new IPEndPoint(*address));
   }
   write_callback_ = callback;
   return ERR_IO_PENDING;
 }
 
 int UDPSocketLibevent::Connect(const IPEndPoint& address) {
+  net_log_.BeginEvent(
+      NetLog::TYPE_UDP_CONNECT,
+      make_scoped_refptr(new NetLogStringParameter("address",
+                                                   address.ToString())));
+  int rv = InternalConnect(address);
+  net_log_.EndEventWithNetErrorCode(NetLog::TYPE_UDP_CONNECT, rv);
+  return rv;
+}
+
+int UDPSocketLibevent::InternalConnect(const IPEndPoint& address) {
   DCHECK(!is_connected());
   DCHECK(!remote_address_.get());
   int rv = CreateSocket(address);
   if (rv < 0)
     return rv;
 
   if (bind_type_ == DatagramSocket::RANDOM_BIND)
     rv = RandomBind(address);
   // else connect() does the DatagramSocket::DEFAULT_BIND
 
@@ skipping 51 matching lines @@
   if (result != ERR_IO_PENDING) {
     read_buf_ = NULL;
     read_buf_len_ = 0;
     recv_from_address_ = NULL;
     bool ok = read_socket_watcher_.StopWatchingFileDescriptor();
     DCHECK(ok);
     DoReadCallback(result);
   }
 }
 
+void UDPSocketLibevent::ProcessSuccessfulRead(int num_bytes,
+                                              const char* bytes,
+                                              const IPEndPoint* address) const {
+  base::StatsCounter read_bytes("udp.read_bytes");
+  read_bytes.Add(num_bytes);
+
+  if (net_log_.IsLoggingAllEvents()) {
+    net_log_.AddEvent(
+        NetLog::TYPE_UDP_BYTES_RECEIVED,
+        make_scoped_refptr(
+            new UDPDataTransferNetLogParam(num_bytes, bytes,
+                                           net_log_.IsLoggingBytes(),
+                                           address)));
+  }
+}
+
 int UDPSocketLibevent::CreateSocket(const IPEndPoint& address) {
   socket_ = socket(address.GetFamily(), SOCK_DGRAM, 0);
   if (socket_ == kInvalidSocket)
     return MapSystemError(errno);
   if (SetNonBlocking(socket_)) {
     const int err = MapSystemError(errno);
     Close();
     return err;
   }
   return OK;
 }
 
 void UDPSocketLibevent::DidCompleteWrite() {
   int result = InternalSendTo(write_buf_, write_buf_len_,
                               send_to_address_.get());
   if (result >= 0) {
-    base::StatsCounter write_bytes("udp.write_bytes");
-    write_bytes.Add(result);
+    ProcessSuccessfulWrite(result, write_buf_->data(), send_to_address_.get());
   } else {
     result = MapSystemError(errno);
+    if (result != ERR_IO_PENDING)
+      net_log_.AddEventWithNetErrorCode(NetLog::TYPE_UDP_SEND_ERROR, result);
   }
 
   if (result != ERR_IO_PENDING) {
     write_buf_ = NULL;
     write_buf_len_ = 0;
     send_to_address_.reset();
     write_socket_watcher_.StopWatchingFileDescriptor();
     DoWriteCallback(result);
   }
 }
 
+void UDPSocketLibevent::ProcessSuccessfulWrite(
+    int num_bytes,
+    const char* bytes,
+    const IPEndPoint* address) const {
+  base::StatsCounter write_bytes("udp.write_bytes");
+  write_bytes.Add(num_bytes);
+  if (net_log_.IsLoggingAllEvents()) {
+    net_log_.AddEvent(
+        NetLog::TYPE_UDP_BYTES_SENT,
+        make_scoped_refptr(
+            new UDPDataTransferNetLogParam(num_bytes, bytes,
+                                           net_log_.IsLoggingBytes(),
+                                           address)));
+  }
+}
+
 int UDPSocketLibevent::InternalRecvFrom(IOBuffer* buf, int buf_len,
                                         IPEndPoint* address) {
   int bytes_transferred;
   int flags = 0;
 
   struct sockaddr_storage addr_storage;
   socklen_t addr_len = sizeof(addr_storage);
   struct sockaddr* addr = reinterpret_cast<struct sockaddr*>(&addr_storage);
 
   bytes_transferred =
       HANDLE_EINTR(recvfrom(socket_,
                             buf->data(),
                             buf_len,
                             flags,
                             addr,
                             &addr_len));
   int result;
   if (bytes_transferred >= 0) {
     result = bytes_transferred;
-    base::StatsCounter read_bytes("udp.read_bytes");
-    read_bytes.Add(bytes_transferred);
+    ProcessSuccessfulRead(bytes_transferred, buf->data(), address);
     if (address) {
       if (!address->FromSockAddr(addr, addr_len))
         result = ERR_FAILED;
     }
   } else {
     result = MapSystemError(errno);
   }
   return result;
 }
 
@@ skipping 37 matching lines @@
 
   for (int i = 0; i < kBindRetries; ++i) {
     int rv = DoBind(IPEndPoint(ip, rand_int_cb_.Run(kPortStart, kPortEnd)));
     if (rv == OK || rv != ERR_ADDRESS_IN_USE)
       return rv;
   }
   return DoBind(IPEndPoint(ip, 0));
 }
 
 }  // namespace net