BUG: socketSelect(..., timeout): failed timeout on Unix for certain fractional timeouts about wishlist-for-r

[HenrikBengtsson]

Thxs. So everything works fine for you with respect to this issue (which has been fixed; also for you).

[HenrikBengtsson]

Troubleshooting

Following the code, we find that the internal function of interest is R_SocketWaitMultiple() in src/modules/internet/Rsock.c. Dropping all non-Unix code, this code looks like:

/**** FIXME: merge with R_SocketWait */
/**** FIXME: add timeout argument instead of using global?? */
int R_SocketWaitMultiple(int nsock, int *insockfd, int *ready, int *write,
			 double mytimeout)
{
    fd_set rfd, wfd;
    struct timeval tv;
    double used = 0.0;
    int nready = 0;

    while(1) {
	int maxfd = 0, howmany, i;
	R_ProcessEvents();
#ifdef Unix
	if(R_wait_usec > 0) {
	    int delta;
	    if (mytimeout < 0 || R_wait_usec / 1e-6 < mytimeout - used)
		delta = R_wait_usec;
	    else
		delta = (int)(1e6 * (mytimeout - used));
	    tv.tv_sec = 0;
	    tv.tv_usec = delta;
	} else if (mytimeout >= 0) {
	    tv.tv_sec = (int)(mytimeout - used);
	    tv.tv_usec = (int)(1e6 * (mytimeout - used - tv.tv_sec));
	} else {  /* always poll occationally--not really necessary */
	    tv.tv_sec = 60;
	    tv.tv_usec = 0;
	}
#else	
[...]
#endif


#ifdef Unix
	maxfd = setSelectMask(R_InputHandlers, &rfd);
#else	
[...]
#endif
	FD_ZERO(&wfd);
	for (i = 0; i < nsock; i++) {
	    if(write[i]) FD_SET(insockfd[i], &wfd);
	    else FD_SET(insockfd[i], &rfd);
	    if(maxfd < insockfd[i]) maxfd = insockfd[i];
	}

	/* increment used value _before_ the select in case select
	   modifies tv (as Linux does) */
	used += tv.tv_sec + 1e-6 * tv.tv_usec;

	howmany = R_SelectEx(maxfd+1, &rfd, &wfd, NULL, &tv, NULL);

	if (howmany < 0) {
	    return -socket_errno();
	}
	if (howmany == 0) {
	    if(mytimeout >= 0 && used >= mytimeout) {
		for (i = 0; i < nsock; i++)
		    ready[i] = 0; /* FALSE */
		return 0;
	    }
	    continue;
	}

	for (i = 0; i < nsock; i++)
	    if ((!write[i] && FD_ISSET(insockfd[i], &rfd)) ||
		(write[i] && FD_ISSET(insockfd[i], &wfd))) {
		ready[i] = 1; /* TRUE */
		nready++;
	    }
	    else ready[i] = 0; /* FALSE */

#ifdef Unix
	if(howmany > nready) {
	    /* one of the extras is ready */
	    InputHandler *what;
	    what = getSelectedHandler(R_InputHandlers, &rfd);
	    if(what != NULL) what->handler((void*) NULL);
	    continue;
	}
#endif
	/* some sockets are ready */
	break;
    }
    return nready;
}

where R_wait_usec, which is probably the "global" referred to in the comment, is defined in src/include/R_ext/eventloop.h:

extern int R_wait_usec;

and set as follows in src/unix/sys-std.c:

int R_wait_usec = 0; /* 0 means no timeout */

Running a grep -F "R_wait_usec" -r --include="*.c" src/ does not show any obvious assignments / changes to this global variable. In other words, I think one can assume that R_wait_usec == 0 in the above function.

[HenrikBengtsson]

After debugging / inspecting mytimeout, used, tv.tv_sec and tv.tv_usec, I think the problem lies in the test used >= mytimeout does not account for the fact that there is a rounding error happening in the calculation of tv.tv_usec and this rounding error is related to the precision of tv which is 1 ms.

Here is an example (in R) illustrating the problem:

> mytimeout <- 1.9
> used <- 0
> tv.tv_sec = as.integer(mytimeout - used);
> tv.tv_usec = as.integer(1e6 * (mytimeout - used - tv.tv_sec));
> tv.tv_sec
[1] 1
>  tv.tv_usec
[1] 899999

Note how tv.tv_usec became 899999L and not 900000L. This will result in:

> used <- used + tv.tv_sec + 1e-6 * tv.tv_usec;
> used
[1] 1.899999

and therefore:

> used - mytimeout
[1] -1e-06

such that the following test fails:

> used >= mytimeout
[1] FALSE

In order to account for the precision in tv, which is 1 ms, the proper test should probably be:

> used + 1e-6 >= mytimeout
[1] TRUE

[HenrikBengtsson]

Here's a patch:

$ svn diff src/modules/internet/Rsock.c
Index: src/modules/internet/Rsock.c
===================================================================
--- src/modules/internet/Rsock.c	(revision 71859)
+++ src/modules/internet/Rsock.c	(working copy)
@@ -260,7 +260,7 @@
 	    return -socket_errno();
 	}
 	if (howmany == 0) {
-	    if(used >= timeout) return 1;
+	    if(used + 1e-6 >= timeout) return 1;
 	    continue;
 	}
 
@@ -345,7 +345,7 @@
 	    return -socket_errno();
 	}
 	if (howmany == 0) {
-	    if(mytimeout >= 0 && used >= mytimeout) {
+	    if(mytimeout >= 0 && used + 1e-6 >= mytimeout) {
 		for (i = 0; i < nsock; i++)
 		    ready[i] = 0; /* FALSE */
 		return 0;

[HenrikBengtsson]

Patch submitted, cf. PR #17203.

[HenrikBengtsson]

UPDATE: Sent a follow up to my R-devel thread 'socketSelect(..., timeout): non-integer timeouts in (0, 2) (?) equal infinite timeout on Linux - weird' on 2016-10-01 (https://stat.ethz.ch/pipermail/r-devel/2016-October/073218.html) in order to try to get this fixed.

[HenrikBengtsson]

This has been fixed in R-devel rev73470 and I've verified it using:

> sessionInfo()
R Under development (unstable) (2017-10-05 r73472)
Platform: x86_64-pc-linux-gnu (64-bit)
Running under: Ubuntu 16.04.3 LTS

[HenrikBengtsson]

This issue is there is R 3.4.2 but has been fixed in R (>= 3.4.3);

> setupConnection <- function(host = "localhost", port = 11001L) {
+   Rscript <- file.path(R.home("bin"), "Rscript")
+   cmd <- sprintf("Sys.sleep(1) ..." ... [TRUNCATED] 

> con <- setupConnection()
A connection with           
                    > print(con)

description "->localhost:11001"
class       "sockconn"         
mode        "a+b"              
text        "binary"           
opened      "opened"           
can read    "yes"              
can write   "yes"              
A connection with                                           
description "<-localhost.localdomain:11001"
class       "sockconn"                     
mode        "a+b"                          
text        "binary"                       
opened      "opened"                       
can read    "yes"                          
can write   "yes"                          

> t <- system.time(r <- socketSelect(list(con), write = FALSE, timeout = 1.9))

> print(t)
   user  system elapsed 
  0.001   0.000   1.902 

> print(r)
[1] FALSE

on

> sessionInfo()
R version 3.4.3 (2017-11-30)
Platform: x86_64-pc-linux-gnu (64-bit)

Matrix products: default
BLAS: /home/shared/cbc/software_cbc/R/R-3.4.3-20171130/lib64/R/lib/libRblas.so
LAPACK: /home/shared/cbc/software_cbc/R/R-3.4.3-20171130/lib64/R/lib/libRlapack.so

locale:
[1] C

attached base packages:
[1] stats     graphics  grDevices utils     datasets  methods   base     

loaded via a namespace (and not attached):
[1] compiler_3.4.3 tools_3.4.3   

@hanase, maybe this was/is related to your RStudio issue?

[HenrikBengtsson]

@wlandau, regarding HenrikBengtsson/future#99, what do you get when you run:

setupConnection <- function(delay = 1.0, lifespan = 20.0, host = "localhost", port = 11001L) {
  Rscript <- file.path(R.home("bin"), "Rscript")
  cmd <- sprintf("Sys.sleep(%g); invisible(socketConnection('%s', port = %d, server = FALSE, blocking = TRUE, open = 'a+b')); Sys.sleep(%g)", delay, host, port, lifespan)
  system2(Rscript, args = c("-e", shQuote(cmd)), wait = FALSE)
  socketConnection(host, port = port, server = TRUE, blocking = TRUE, open = 'a+b')
}

testSocketSelectTimeout <- function(..., timeouts = c(0, 0.2, 1, 1.2, 2, 2.2, 3), tol = 0.1) {
  con <- setupConnection(...)
  on.exit(close(con))
  for (timeout in timeouts) {
    t <- system.time({
      ans <- socketSelect(list(con), write = FALSE, timeout = timeout)
    })
    stopifnot(!ans) ## Nothing should be available
    print(t)
    stopifnot(abs(t[["elapsed"]] - timeout) < tol)
  }
}  

testSocketSelectTimeout()
##   user  system elapsed 
##      0       0       0 
##   user  system elapsed 
##    0.0     0.0     0.2 
##   user  system elapsed 
##  0.000   0.000   1.001 
##   user  system elapsed 
##  0.000   0.000   1.201 
##   user  system elapsed 
##  0.000   0.000   2.002 
##   user  system elapsed 
##  0.000   0.000   2.201 
##   user  system elapsed 
##  0.000   0.000   3.001

Above is from R 4.0.4 on Ubuntu 18.04

[wlandau]

Thanks, Henrik. I get pretty much the same result on Mac OS 10.15.7 (and RHEL 7.8).

setupConnection <- function(delay = 1.0, lifespan = 20.0, host = "localhost", port = 11001L) {
  Rscript <- file.path(R.home("bin"), "Rscript")
  cmd <- sprintf("Sys.sleep(%g); invisible(socketConnection('%s', port = %d, server = FALSE, blocking = TRUE, open = 'a+b')); Sys.sleep(%g)", delay, host, port, lifespan)
  system2(Rscript, args = c("-e", shQuote(cmd)), wait = FALSE)
  socketConnection(host, port = port, server = TRUE, blocking = TRUE, open = 'a+b')
}

testSocketSelectTimeout <- function(..., timeouts = c(0, 0.2, 1, 1.2, 2, 2.2, 3), tol = 0.1) {
  con <- setupConnection(...)
  on.exit(close(con))
  for (timeout in timeouts) {
    t <- system.time({
      ans <- socketSelect(list(con), write = FALSE, timeout = timeout)
    })
    stopifnot(!ans) ## Nothing should be available
    print(t)
    stopifnot(abs(t[["elapsed"]] - timeout) < tol)
  }
}

testSocketSelectTimeout()
#>    user  system elapsed 
#>       0       0       0 
#>    user  system elapsed 
#>   0.000   0.000   0.202 
#>    user  system elapsed 
#>   0.000   0.000   1.002 
#>    user  system elapsed 
#>   0.000   0.000   1.201 
#>    user  system elapsed 
#>   0.000   0.001   2.004 
#>    user  system elapsed 
#>   0.000   0.000   2.201 
#>    user  system elapsed 
#>   0.000   0.000   3.002