---------------------
PatchSet 12429 
Date: 2009/02/02 11:10:53
Author: hno
Branch: SQUID_2_7
Tag: (none) 
Log:
Correct latency measurements

We need to read the current time just after asking the kernel for pending
events or response time measuremet will get messed up by the select loop delay.

Members: 
	src/comm_devpoll.c:1.3->1.3.6.1 
	src/comm_epoll.c:1.29->1.29.2.1 
	src/comm_kqueue.c:1.12.2.1->1.12.2.2 
	src/comm_poll.c:1.24->1.24.2.1 
	src/comm_poll_win32.c:1.1->1.1.6.1 
	src/comm_select.c:1.82->1.82.2.1 
	src/comm_select_simple.c:1.4->1.4.2.1 
	src/comm_select_win32.c:1.8->1.8.2.1 

Index: squid/src/comm_devpoll.c
===================================================================
RCS file: /cvsroot/squid/squid/src/comm_devpoll.c,v
retrieving revision 1.3
retrieving revision 1.3.6.1
diff -u -r1.3 -r1.3.6.1
--- squid/src/comm_devpoll.c	27 May 2007 14:17:50 -0000	1.3
+++ squid/src/comm_devpoll.c	2 Feb 2009 11:10:53 -0000	1.3.6.1
@@ -1,6 +1,6 @@
 
 /*
- * $Id: comm_devpoll.c,v 1.3 2007/05/27 14:17:50 adrian Exp $
+ * $Id: comm_devpoll.c,v 1.3.6.1 2009/02/02 11:10:53 hno Exp $
  *
  * DEBUG: section 5     Socket Functions
  *
@@ -190,7 +190,7 @@
 do_comm_select(int msec)
 {
     int i;
-    int num;
+    int num, saved_errno;
 
     statCounter.syscalls.polls++;
 
@@ -202,11 +202,11 @@
     comm_flush_updates();
 
     num = ioctl(devpoll_fd, DP_POLL, &do_poll);
-    debug(5, 5) ("do_comm_select: ioctl() returned %d fds\n", num);
-
+    saved_errno = errno;
+    getCurrentTime();
+    debug(5, 5) ("do_comm_select: %d fds ready\n", num);
     if (num < 0) {
-	getCurrentTime();
-	if (ignoreErrno(errno))
+	if (ignoreErrno(saved_errno))
 	    return COMM_OK;
 
 	debug(5, 1) ("comm_select: devpoll ioctl(DP_POLL) failure: %s\n", xstrerror());
Index: squid/src/comm_epoll.c
===================================================================
RCS file: /cvsroot/squid/squid/src/comm_epoll.c,v
retrieving revision 1.29
retrieving revision 1.29.2.1
diff -u -r1.29 -r1.29.2.1
--- squid/src/comm_epoll.c	20 May 2007 13:45:10 -0000	1.29
+++ squid/src/comm_epoll.c	2 Feb 2009 11:10:53 -0000	1.29.2.1
@@ -1,6 +1,6 @@
 
 /*
- * $Id: comm_epoll.c,v 1.29 2007/05/20 13:45:10 adrian Exp $
+ * $Id: comm_epoll.c,v 1.29.2.1 2009/02/02 11:10:53 hno Exp $
  *
  * DEBUG: section 5     Socket Functions
  *
@@ -168,7 +168,7 @@
 do_comm_select(int msec)
 {
     int i;
-    int num;
+    int num, saved_errno;
 
     if (epoll_fds == 0) {
 	assert(shutting_down);
@@ -176,9 +176,11 @@
     }
     statCounter.syscalls.polls++;
     num = epoll_wait(kdpfd, events, MAX_EVENTS, msec);
+    saved_errno = errno;
+    getCurrentTime();
+    debug(5, 5) ("do_comm_select: %d fds ready\n", num);
     if (num < 0) {
-	getCurrentTime();
-	if (ignoreErrno(errno))
+	if (ignoreErrno(saved_errno))
 	    return COMM_OK;
 
 	debug(5, 1) ("comm_select: epoll failure: %s\n", xstrerror());
Index: squid/src/comm_kqueue.c
===================================================================
RCS file: /cvsroot/squid/squid/src/comm_kqueue.c,v
retrieving revision 1.12.2.1
retrieving revision 1.12.2.2
diff -u -r1.12.2.1 -r1.12.2.2
--- squid/src/comm_kqueue.c	4 May 2008 23:23:13 -0000	1.12.2.1
+++ squid/src/comm_kqueue.c	2 Feb 2009 11:10:53 -0000	1.12.2.2
@@ -1,6 +1,6 @@
 
 /*
- * $Id: comm_kqueue.c,v 1.12.2.1 2008/05/04 23:23:13 hno Exp $
+ * $Id: comm_kqueue.c,v 1.12.2.2 2009/02/02 11:10:53 hno Exp $
  *
  * DEBUG: section 5     Socket Functions
  *
@@ -141,7 +141,7 @@
 do_comm_select(int msec)
 {
     int i;
-    int num;
+    int num, saved_errno;
     struct timespec timeout;
 
     timeout.tv_sec = msec / 1000;
@@ -149,10 +149,12 @@
 
     statCounter.syscalls.polls++;
     num = kevent(kq, kqlst, kqoff, ke, kqmax, &timeout);
+    saved_errno = errno;
+    getCurrentTime();
+    debug(5, 5) ("do_comm_select: %d fds ready\n", num);
     kqoff = 0;
     if (num < 0) {
-	getCurrentTime();
-	if (ignoreErrno(errno))
+	if (ignoreErrno(saved_errnoerrno))
 	    return COMM_OK;
 
 	debug(5, 1) ("comm_select: kevent failure: %s\n", xstrerror());
Index: squid/src/comm_poll.c
===================================================================
RCS file: /cvsroot/squid/squid/src/comm_poll.c,v
retrieving revision 1.24
retrieving revision 1.24.2.1
diff -u -r1.24 -r1.24.2.1
--- squid/src/comm_poll.c	20 May 2007 13:45:10 -0000	1.24
+++ squid/src/comm_poll.c	2 Feb 2009 11:10:53 -0000	1.24.2.1
@@ -1,6 +1,6 @@
 
 /*
- * $Id: comm_poll.c,v 1.24 2007/05/20 13:45:10 adrian Exp $
+ * $Id: comm_poll.c,v 1.24.2.1 2009/02/02 11:10:53 hno Exp $
  *
  * DEBUG: section 5     Socket Functions
  *
@@ -119,7 +119,7 @@
 static int
 do_comm_select(int msec)
 {
-    int num;
+    int num, saved_errno;
     int i;
 
     if (nfds == 0) {
@@ -128,9 +128,11 @@
     }
     statCounter.syscalls.selects++;
     num = poll(pfds, nfds, msec);
+    saved_errno = errno;
+    getCurrentTime();
+    debug(5, 5) ("do_comm_select: %d fds ready\n", num);
     if (num < 0) {
-	getCurrentTime();
-	if (ignoreErrno(errno))
+	if (ignoreErrno(saved_errno))
 	    return COMM_OK;
 
 	debug(5, 1) ("comm_select: poll failure: %s\n", xstrerror());
Index: squid/src/comm_poll_win32.c
===================================================================
RCS file: /cvsroot/squid/squid/src/comm_poll_win32.c,v
retrieving revision 1.1
retrieving revision 1.1.6.1
diff -u -r1.1 -r1.1.6.1
--- squid/src/comm_poll_win32.c	28 Oct 2006 00:35:12 -0000	1.1
+++ squid/src/comm_poll_win32.c	2 Feb 2009 11:10:53 -0000	1.1.6.1
@@ -1,6 +1,6 @@
 
 /*
- * $Id: comm_poll_win32.c,v 1.1 2006/10/28 00:35:12 hno Exp $
+ * $Id: comm_poll_win32.c,v 1.1.6.1 2009/02/02 11:10:53 hno Exp $
  *
  * DEBUG: section 5     Socket Functions
  *
@@ -112,7 +112,7 @@
 static int
 do_comm_select(int msec)
 {
-    int num;
+    int num, saved_errno;
     int i;
 
     if (nfds == 0) {
@@ -121,9 +121,11 @@
     }
     statCounter.syscalls.selects++;
     num = WSAPoll(pfds, nfds, msec);
+    saved_errno = errno;
+    getCurrentTime();
+    debug(5, 5) ("do_comm_select: %d fds ready\n", num);
     if (num < 0) {
-	getCurrentTime();
-	if (ignoreErrno(errno))
+	if (ignoreErrno(saved_errno))
 	    return COMM_OK;
 
 	debug(5, 1) ("comm_select: poll failure: %s\n", xstrerror());
Index: squid/src/comm_select.c
===================================================================
RCS file: /cvsroot/squid/squid/src/comm_select.c,v
retrieving revision 1.82
retrieving revision 1.82.2.1
diff -u -r1.82 -r1.82.2.1
--- squid/src/comm_select.c	17 Jul 2007 20:34:28 -0000	1.82
+++ squid/src/comm_select.c	2 Feb 2009 11:10:53 -0000	1.82.2.1
@@ -1,6 +1,6 @@
 
 /*
- * $Id: comm_select.c,v 1.82 2007/07/17 20:34:28 hno Exp $
+ * $Id: comm_select.c,v 1.82.2.1 2009/02/02 11:10:53 hno Exp $
  *
  * DEBUG: section 5     Socket Functions
  *
@@ -126,7 +126,7 @@
 static int
 do_comm_select(int msec)
 {
-    int num;
+    int num, saved_errno;
     struct timeval tv;
     fd_mask *rfdsp = (fd_mask *) current_readfds;
     fd_mask *wfdsp = (fd_mask *) current_writefds;
@@ -146,10 +146,11 @@
     tv.tv_usec = (msec % 1000) * 1000;
     statCounter.syscalls.selects++;
     num = select(Biggest_FD + 1, current_readfds, current_writefds, current_errfds, &tv);
-
+    saved_errno = errno;
+    getCurrentTime();
+    debug(5, 5) ("do_comm_select: %d fds ready\n", num);
     if (num < 0) {
-	getCurrentTime();
-	if (ignoreErrno(errno))
+	if (ignoreErrno(saved_errno))
 	    return COMM_OK;
 
 	debug(5, 1) ("comm_select: select failure: %s\n", xstrerror());
Index: squid/src/comm_select_simple.c
===================================================================
RCS file: /cvsroot/squid/squid/src/comm_select_simple.c,v
retrieving revision 1.4
retrieving revision 1.4.2.1
diff -u -r1.4 -r1.4.2.1
--- squid/src/comm_select_simple.c	20 May 2007 13:45:11 -0000	1.4
+++ squid/src/comm_select_simple.c	2 Feb 2009 11:10:53 -0000	1.4.2.1
@@ -1,6 +1,6 @@
 
 /*
- * $Id: comm_select_simple.c,v 1.4 2007/05/20 13:45:11 adrian Exp $
+ * $Id: comm_select_simple.c,v 1.4.2.1 2009/02/02 11:10:53 hno Exp $
  *
  * DEBUG: section 5     Socket Functions
  *
@@ -106,7 +106,7 @@
 static int
 do_comm_select(int msec)
 {
-    int num;
+    int num, saved_errno;
     struct timeval tv;
     fd_set readfds;
     fd_set writefds;
@@ -124,10 +124,11 @@
     tv.tv_usec = (msec % 1000) * 1000;
     statCounter.syscalls.selects++;
     num = select(Biggest_FD + 1, &readfds, &writefds, &errfds, &tv);
-
+    saved_errno = errno;
+    getCurrentTime();
+    debug(5, 5) ("do_comm_select: %d fds ready\n", num);
     if (num < 0) {
-	getCurrentTime();
-	if (ignoreErrno(errno))
+	if (ignoreErrno(saved_errno))
 	    return COMM_OK;
 
 	debug(5, 1) ("comm_select: select failure: %s\n", xstrerror());
Index: squid/src/comm_select_win32.c
===================================================================
RCS file: /cvsroot/squid/squid/src/comm_select_win32.c,v
retrieving revision 1.8
retrieving revision 1.8.2.1
diff -u -r1.8 -r1.8.2.1
--- squid/src/comm_select_win32.c	20 May 2007 13:45:11 -0000	1.8
+++ squid/src/comm_select_win32.c	2 Feb 2009 11:10:53 -0000	1.8.2.1
@@ -1,6 +1,6 @@
 
 /*
- * $Id: comm_select_win32.c,v 1.8 2007/05/20 13:45:11 adrian Exp $
+ * $Id: comm_select_win32.c,v 1.8.2.1 2009/02/02 11:10:53 hno Exp $
  *
  * DEBUG: section 5     Socket Functions
  *
@@ -103,7 +103,7 @@
 static int
 do_comm_select(int msec)
 {
-    int num;
+    int num, saved_errno;
     struct timeval tv;
     fd_set readfds;
     fd_set writefds;
@@ -121,10 +121,11 @@
     tv.tv_usec = (msec % 1000) * 1000;
     statCounter.syscalls.selects++;
     num = select(Biggest_FD + 1, &readfds, &writefds, &errfds, &tv);
-
+    saved_errno = errno;
+    getCurrentTime();
+    debug(5, 5) ("do_comm_select: %d fds ready\n", num);
     if (num < 0) {
-	getCurrentTime();
-	if (ignoreErrno(errno))
+	if (ignoreErrno(saved_errno))
 	    return COMM_OK;
 
 	debug(5, 1) ("comm_select: select failure: %s\n", xstrerror());