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) {
+      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,
+                                      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);

[eroman, 2011/10/11 20:50:07]

So this can only complete synchronously?

[mmenke, 2011/10/11 21:06:27]

Apparently not.  I wondered that, too, but there's no callback for it in the
Linux or Windows code, and the unit tests assume synchronous Connect success.

This behavior does make sense, since it's not actually connecting anything, but
I can't find it documented anywhere as guaranteed behavior.

+  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);
+
+  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);
+  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