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 89 matching lines @@
   DCHECK_GT(buf_len, 0);
 
   int nread = InternalRecvFrom(buf, buf_len, address);
   if (nread != ERR_IO_PENDING)
     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);
+    return LogRead(MapSystemError(errno), NULL, 0, NULL, NULL);
   }
 
   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 13 matching lines @@
                                      int buf_len,
                                      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);
-    return nwrite;
-  }
+  if (nwrite >= 0)
+    return LogWrite(nwrite, buf->data(), address);

[Sergey Ulanov, 2011/10/17 17:48:13]

Can we move this to InternalSendTo() so that it is consistent with
InternalRecvFrom()?

[mmenke, 2011/10/17 19:41:38]

Done.

   if (errno != EAGAIN && errno != EWOULDBLOCK)
-    return MapSystemError(errno);
+    return LogWrite(MapSystemError(errno), NULL, NULL);
 
   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);
+    return LogWrite(MapSystemError(errno), NULL, NULL);
   }
 
   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);
   }
 }
 
+int UDPSocketLibevent::LogRead(int result,
+                               const char* bytes,
+                               socklen_t addr_len,
+                               const sockaddr* addr,
+                               IPEndPoint* address) const {
+  DCHECK(result < 0 || addr_len > 0);
+  DCHECK(result < 0 || addr != NULL);
+
+  if (result >= 0 && address) {
+    if (!address->FromSockAddr(addr, addr_len))

[Sergey Ulanov, 2011/10/17 17:48:13]

I think that conversion of the address should stay in InternalRecvFrom()

[mmenke, 2011/10/17 19:41:38]

Done.  If address is NULL and we're logging, I still want to log it (As I see
this is a potential source of errors).  To keep things simple, I now just always
call IPEndPoint::FromSockAddr instead of using an existing IPEndPoint if we have
it.

+      result = ERR_FAILED;
+  }
+
+  if (result < 0) {
+    net_log_.AddEventWithNetErrorCode(NetLog::TYPE_UDP_RECEIVE_ERROR, result);
+    return result;
+  }
+
+  if (net_log_.IsLoggingAllEvents()) {
+    // Get address for logging, if |address| is NULL.
+    IPEndPoint address_on_stack;
+    if (!address) {
+      if (address_on_stack.FromSockAddr(addr, addr_len))
+        address = &address_on_stack;
+    }
+    net_log_.AddEvent(
+        NetLog::TYPE_UDP_BYTES_RECEIVED,
+        make_scoped_refptr(
+            new UDPDataTransferNetLogParam(result, bytes,
+                                           net_log_.IsLoggingBytes(),
+                                           address)));
+  }
+
+  base::StatsCounter read_bytes("udp.read_bytes");
+  read_bytes.Add(result);
+  return result;
+}
+
 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);
-  } else {
+  if (result < 0)
     result = MapSystemError(errno);
-  }
+
+  if (result != ERR_IO_PENDING)
+    result = LogWrite(result, write_buf_->data(), send_to_address_.get());
 
   if (result != ERR_IO_PENDING) {
     write_buf_ = NULL;
     write_buf_len_ = 0;
     send_to_address_.reset();
     write_socket_watcher_.StopWatchingFileDescriptor();
     DoWriteCallback(result);
   }
 }
 
+int UDPSocketLibevent::LogWrite(int result,
+                                const char* bytes,
+                                const IPEndPoint* address) const {
+  if (result < 0) {
+    net_log_.AddEventWithNetErrorCode(NetLog::TYPE_UDP_SEND_ERROR, result);
+    return result;
+  }
+
+  if (net_log_.IsLoggingAllEvents()) {
+    net_log_.AddEvent(
+        NetLog::TYPE_UDP_BYTES_SENT,
+        make_scoped_refptr(
+            new UDPDataTransferNetLogParam(result, bytes,
+                                           net_log_.IsLoggingBytes(),
+                                           address)));
+  }
+
+  base::StatsCounter write_bytes("udp.write_bytes");
+  write_bytes.Add(result);
+  return result;
+}
+
 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);
-    if (address) {
-      if (!address->FromSockAddr(addr, addr_len))
-        result = ERR_FAILED;
-    }
   } else {
     result = MapSystemError(errno);
   }
+  if (result != ERR_IO_PENDING)
+    LogRead(result, buf->data(), addr_len, addr, address);
   return result;
 }
 
 int UDPSocketLibevent::InternalSendTo(IOBuffer* buf, int buf_len,
                                       const IPEndPoint* address) {
   struct sockaddr_storage addr_storage;
   size_t addr_len = sizeof(addr_storage);
   struct sockaddr* addr = reinterpret_cast<struct sockaddr*>(&addr_storage);
 
   if (!address) {
@@ skipping 30 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