Compute and pring the time that it takes to execute system calls. This data...

sandbox/linux/seccomp/socketcall.cc

Index: sandbox/linux/seccomp/socketcall.cc
===================================================================
--- sandbox/linux/seccomp/socketcall.cc	(revision 41782)
+++ sandbox/linux/seccomp/socketcall.cc	(working copy)
@@ -11,7 +11,8 @@
 
 ssize_t Sandbox::sandbox_recvfrom(int sockfd, void* buf, size_t len, int flags,
                                   void* from, socklen_t* fromlen) {
-  Debug::syscall(__NR_recvfrom, "Executing handler");
+  long long tm;
+  Debug::syscall(&tm, __NR_recvfrom, "Executing handler");
 
   SysCalls sys;
   if (!from && !flags) {
@@ -20,8 +21,10 @@
     Debug::message("Replaced recv() with call to read()");
     ssize_t rc = sys.read(sockfd, buf, len);
     if (rc < 0) {
+      Debug::elapsed(tm, __NR_recvfrom);
       return -sys.my_errno;
     } else {
+      Debug::elapsed(tm, __NR_recvfrom);
       return rc;
     }
   }
@@ -46,11 +49,13 @@
       read(sys, threadFdPub(), &rc, sizeof(rc)) != sizeof(rc)) {
     die("Failed to forward recvfrom() request [sandbox]");
   }
+  Debug::elapsed(tm, __NR_recvfrom);
   return static_cast<int>(rc);
 }
 
 ssize_t Sandbox::sandbox_recvmsg(int sockfd, struct msghdr* msg, int flags) {
-  Debug::syscall(__NR_recvmsg, "Executing handler");
+  long long tm;
+  Debug::syscall(&tm, __NR_recvmsg, "Executing handler");
 
   // We cannot simplify recvmsg() to recvfrom(), recv() or read(), as we do
   // not know whether the caller needs us to set msg->msg_flags.
@@ -72,12 +77,14 @@
       read(sys, threadFdPub(), &rc, sizeof(rc)) != sizeof(rc)) {
     die("Failed to forward recvmsg() request [sandbox]");
   }
+  Debug::elapsed(tm, __NR_recvmsg);
   return static_cast<int>(rc);
 }
 
 size_t Sandbox::sandbox_sendmsg(int sockfd, const struct msghdr* msg,
                                 int flags) {
-  Debug::syscall(__NR_sendmsg, "Executing handler");
+  long long tm;
+  Debug::syscall(&tm, __NR_sendmsg, "Executing handler");
 
   if (msg->msg_iovlen == 1 && msg->msg_controllen == 0) {
     // sendmsg() can sometimes be simplified as sendto()
@@ -111,12 +118,14 @@
       read(sys, threadFdPub(), &rc, sizeof(rc)) != sizeof(rc)) {
     die("Failed to forward sendmsg() request [sandbox]");
   }
+  Debug::elapsed(tm, __NR_sendmsg);
   return static_cast<int>(rc);
 }
 
 ssize_t Sandbox::sandbox_sendto(int sockfd, const void* buf, size_t len,
                                 int flags, const void* to, socklen_t tolen) {
-  Debug::syscall(__NR_sendto, "Executing handler");
+  long long tm;
+  Debug::syscall(&tm, __NR_sendto, "Executing handler");
 
   SysCalls sys;
   if (!to && !flags) {
@@ -125,8 +134,10 @@
     Debug::message("Replaced sendto() with call to write()");
     ssize_t rc = sys.write(sockfd, buf, len);
     if (rc < 0) {
+      Debug::elapsed(tm, __NR_sendto);
       return -sys.my_errno;
     } else {
+      Debug::elapsed(tm, __NR_sendto);
       return rc;
     }
   }
@@ -151,12 +162,14 @@
       read(sys, threadFdPub(), &rc, sizeof(rc)) != sizeof(rc)) {
     die("Failed to forward sendto() request [sandbox]");
   }
+  Debug::elapsed(tm, __NR_sendto);
   return static_cast<int>(rc);
 }
 
 int Sandbox::sandbox_setsockopt(int sockfd, int level, int optname,
                                 const void* optval, socklen_t optlen) {
-  Debug::syscall(__NR_setsockopt, "Executing handler");
+  long long tm;
+  Debug::syscall(&tm, __NR_setsockopt, "Executing handler");
 
   struct {
     int        sysnum;
@@ -178,12 +191,14 @@
       read(sys, threadFdPub(), &rc, sizeof(rc)) != sizeof(rc)) {
     die("Failed to forward setsockopt() request [sandbox]");
   }
+  Debug::elapsed(tm, __NR_setsockopt);
   return static_cast<int>(rc);
 }
 
 int Sandbox::sandbox_getsockopt(int sockfd, int level, int optname,
                                 void* optval, socklen_t* optlen) {
-  Debug::syscall(__NR_getsockopt, "Executing handler");
+  long long tm;
+  Debug::syscall(&tm, __NR_getsockopt, "Executing handler");
 
   struct {
     int        sysnum;
@@ -205,6 +220,7 @@
       read(sys, threadFdPub(), &rc, sizeof(rc)) != sizeof(rc)) {
     die("Failed to forward getsockopt() request [sandbox]");
   }
+  Debug::elapsed(tm, __NR_getsockopt);
   return static_cast<int>(rc);
 }
 
@@ -553,11 +569,13 @@
 };
 
 int Sandbox::sandbox_socketcall(int call, void* args) {
-  Debug::syscall(__NR_socketcall, "Executing handler", call);
+  long long tm;
+  Debug::syscall(&tm, __NR_socketcall, "Executing handler", call);
 
   // When demultiplexing socketcall(), only accept calls that have a valid
   // "call" opcode.
   if (call < SYS_SOCKET || call > SYS_ACCEPT4) {
+    Debug::elapsed(tm, __NR_socketcall, call);
     return -ENOSYS;
   }
 
@@ -647,8 +665,10 @@
                            request->socketcall_req.args.send.buf,
                            request->socketcall_req.args.send.len);
     if (rc < 0) {
+      Debug::elapsed(tm, __NR_socketcall, call);
       return -sys.my_errno;
     } else {
+      Debug::elapsed(tm, __NR_socketcall, call);
       return rc;
     }
   }
@@ -670,8 +690,10 @@
                           request->socketcall_req.args.recv.buf,
                           request->socketcall_req.args.recv.len);
     if (rc < 0) {
+      Debug::elapsed(tm, __NR_socketcall, call);
       return -sys.my_errno;
     } else {
+      Debug::elapsed(tm, __NR_socketcall, call);
       return rc;
     }
   }
@@ -708,6 +730,7 @@
       read(sys, threadFdPub(), &rc, sizeof(rc)) != sizeof(rc)) {
     die("Failed to forward socketcall() request [sandbox]");
   }
+  Debug::elapsed(tm, __NR_socketcall, call);
   return static_cast<int>(rc);
 }