R devel - Oct 2016 - BUG?: On Linux setTimeLimit() fails to propagate timeout error when it occurs (works on Windows)

setTimeLimit(elapsed=1) causes a timeout error whenever a call takes
more than one second.  For instance, this is how it works on Windows
(R 3.3.1):
> setTimeLimit(elapsed=1)
> Sys.sleep(10); message("done")
Error in Sys.sleep(10) : reached elapsed time limit

Also, the error propagates immediately and causes an interrupt after ~1 second;
> system.time({ Sys.sleep(10); message("done") })
Error in Sys.sleep(10) : reached elapsed time limit
Timing stopped at: 0.01 0 1.02

This works as expected.  However, on Linux (R 3.3.1 but also e.g.
2.11.0, 2.15.3) I get:
> setTimeLimit(elapsed=1)
> system.time({ Sys.sleep(10); message("done") })
Error in Sys.sleep(10) : reached elapsed time limit
Timing stopped at: 0 0 10.01

Note how the timeout error is signaled, but for some reason, it does
not interrupt the Sys.sleep(10) call until after it finishes after 10
seconds.  If you change to Sys.sleep(60) it will take 1 minute. Note
that the following print("done") is not called, so the timeout error
does propagate immediately after Sys.sleep() but not before / during.

This looks like a bug to me.  Can anyone on macOS confirm whether this
is also a problem there or not?

/Henrik
> sessionInfo()
R version 3.3.1 (2016-06-21)
Platform: x86_64-w64-mingw32/x64 (64-bit)
Running under: Windows XP x64 (build 2600) Service Pack 3
> sessionInfo()
R version 3.3.1 (2016-06-21)
Platform: x86_64-pc-linux-gnu (64-bit)
Running under: Ubuntu 16.04.1 LTS
> sessionInfo()
R version 2.11.0 (2010-04-22)
x86_64-unknown-linux-gnu

sessionInfo()
R version 2.15.3 (2013-03-01)
Platform: x86_64-unknown-linux-gnu (64-bit)

On 10/25/2016 9:44 PM, Henrik Bengtsson wrote:
> setTimeLimit(elapsed=1) causes a timeout error whenever a call takes
> more than one second.  For instance, this is how it works on Windows
> (R 3.3.1):
>
>> setTimeLimit(elapsed=1)
>> Sys.sleep(10); message("done")
> Error in Sys.sleep(10) : reached elapsed time limit
>
> Also, the error propagates immediately and causes an interrupt after ~1
second;
>
>> system.time({ Sys.sleep(10); message("done") })
> Error in Sys.sleep(10) : reached elapsed time limit
> Timing stopped at: 0.01 0 1.02
>
> This works as expected.  However, on Linux (R 3.3.1 but also e.g.
> 2.11.0, 2.15.3) I get:
>
>> setTimeLimit(elapsed=1)
>> system.time({ Sys.sleep(10); message("done") })
> Error in Sys.sleep(10) : reached elapsed time limit
> Timing stopped at: 0 0 10.01
>
> Note how the timeout error is signaled, but for some reason, it does
> not interrupt the Sys.sleep(10) call until after it finishes after 10
> seconds.  If you change to Sys.sleep(60) it will take 1 minute. Note
> that the following print("done") is not called, so the timeout
error
> does propagate immediately after Sys.sleep() but not before / during.
>
> This looks like a bug to me.  Can anyone on macOS confirm whether this
> is also a problem there or not?

 > setTimeLimit(elapsed=1)
 > system.time({ Sys.sleep(10); message("done") })
Error in Sys.sleep(10) : reached elapsed time limit
Timing stopped at: 0.003 0.004 0.978
 >
 > sessionInfo()
R version 3.3.1 (2016-06-21)
Platform: x86_64-apple-darwin13.4.0 (64-bit)
Running under: OS X 10.11.6 (El Capitan)

locale:
[1] en_US.UTF-8/en_US.UTF-8/en_US.UTF-8/C/en_US.UTF-8/en_US.UTF-8

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

loaded via a namespace (and not attached):
[1] rsconnect_0.5 tools_3.3.1
Error: reached elapsed time limit
> /Henrik
>
>> sessionInfo()
> R version 3.3.1 (2016-06-21)
> Platform: x86_64-w64-mingw32/x64 (64-bit)
> Running under: Windows XP x64 (build 2600) Service Pack 3
>
>> sessionInfo()
> R version 3.3.1 (2016-06-21)
> Platform: x86_64-pc-linux-gnu (64-bit)
> Running under: Ubuntu 16.04.1 LTS
>
>> sessionInfo()
> R version 2.11.0 (2010-04-22)
> x86_64-unknown-linux-gnu
>
> sessionInfo()
> R version 2.15.3 (2013-03-01)
> Platform: x86_64-unknown-linux-gnu (64-bit)
>
> ______________________________________________
> R-devel at r-project.org mailing list
> https://stat.ethz.ch/mailman/listinfo/r-devel

>>>>> Spencer Graves <spencer.graves at prodsyse.com>
>>>>>     on Tue, 25 Oct 2016 22:02:29 -0500 writes:
    > On 10/25/2016 9:44 PM, Henrik Bengtsson wrote:
    >> setTimeLimit(elapsed=1) causes a timeout error whenever a call
takes
    >> more than one second.  For instance, this is how it works on
Windows
    >> (R 3.3.1):
    >> 
    >>> setTimeLimit(elapsed=1)
    >>> Sys.sleep(10); message("done")
    >> Error in Sys.sleep(10) : reached elapsed time limit
    >> 
    >> Also, the error propagates immediately and causes an interrupt
after ~1 second;
    >> 
    >>> system.time({ Sys.sleep(10); message("done") })
    >> Error in Sys.sleep(10) : reached elapsed time limit
    >> Timing stopped at: 0.01 0 1.02
    >> 
    >> This works as expected.  However, on Linux (R 3.3.1 but also e.g.
    >> 2.11.0, 2.15.3) I get:
    >> 
    >>> setTimeLimit(elapsed=1)
    >>> system.time({ Sys.sleep(10); message("done") })
    >> Error in Sys.sleep(10) : reached elapsed time limit
    >> Timing stopped at: 0 0 10.01
    >> 
    >> Note how the timeout error is signaled, but for some reason, it
does
    >> not interrupt the Sys.sleep(10) call until after it finishes after
10
    >> seconds.  If you change to Sys.sleep(60) it will take 1 minute.
Note
    >> that the following print("done") is not called, so the
timeout error
    >> does propagate immediately after Sys.sleep() but not before /
during.
    >> 
    >> This looks like a bug to me.  Can anyone on macOS confirm whether
this
    >> is also a problem there or not?


    >> setTimeLimit(elapsed=1)
    >> system.time({ Sys.sleep(10); message("done") })
    > Error in Sys.sleep(10) : reached elapsed time limit
    > Timing stopped at: 0.003 0.004 0.978
    >> 
    >> sessionInfo()
    > R version 3.3.1 (2016-06-21)
    > Platform: x86_64-apple-darwin13.4.0 (64-bit)
    > Running under: OS X 10.11.6 (El Capitan)

Thank you, Spencer.

Indeed, confirmed here (Linux Fedora 24) for the most current
'R-devel' and "R 3.3.2 RC".

Also, this "not quite terminating" on Linux is not limited to
Sys.sleep() in case someone was wondering:
> setTimeLimit(elapsed=0.5) ; system.time(P <- sfsmisc::primes(1e7))
   user  system elapsed 
  0.227   0.055   0.281 
> str(P)
 int [1:664579] 2 3 5 7 11 13 17 19 23 29 ...
> setTimeLimit(elapsed=0.5) ; system.time(P <- sfsmisc::primes(3e7))
Error in sfsmisc::primes(3e+07) : reached elapsed time limit
Timing stopped at: 0.538 0.132 0.671


This *is* embarrassing a bit;  ..  probably too late to be fixed
for 3.3.2 .. (and something I'd rather leave to others to fix).

It may be that this has never worked on Linux, or then worked in
Linuxen where some interrupt behavior was different.
At least on my current Linux it does not work, all the way back
to R 2.11.1 .. and setTimeLimit() has not existed for much longer...

Martin


    > locale:
    > [1] en_US.UTF-8/en_US.UTF-8/en_US.UTF-8/C/en_US.UTF-8/en_US.UTF-8

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

    > loaded via a namespace (and not attached):
    > [1] rsconnect_0.5 tools_3.3.1
    > Error: reached elapsed time limit

    >> /Henrik
    >> 
    >>> sessionInfo()
    >> R version 3.3.1 (2016-06-21)
    >> Platform: x86_64-w64-mingw32/x64 (64-bit)
    >> Running under: Windows XP x64 (build 2600) Service Pack 3
    >> 
    >>> sessionInfo()
    >> R version 3.3.1 (2016-06-21)
    >> Platform: x86_64-pc-linux-gnu (64-bit)
    >> Running under: Ubuntu 16.04.1 LTS
    >> 
    >>> sessionInfo()
    >> R version 2.11.0 (2010-04-22)
    >> x86_64-unknown-linux-gnu
    >> 
    >> sessionInfo()
    >> R version 2.15.3 (2013-03-01)
    >> Platform: x86_64-unknown-linux-gnu (64-bit)
    >>

On 26 Oct 2016, at 04:44 , Henrik Bengtsson <henrik.bengtsson at
gmail.com> wrote:
> This looks like a bug to me.  Can anyone on macOS confirm whether this
> is also a problem there or not?
I don't know whether it is a problem ( ;-) ), but it does the same thing
(checked Mavericks, Yosemite and Sierra)

-pd

-- 
Peter Dalgaard, Professor,
Center for Statistics, Copenhagen Business School
Solbjerg Plads 3, 2000 Frederiksberg, Denmark
Phone: (+45)38153501
Office: A 4.23
Email: pd.mes at cbs.dk  Priv: PDalgd at gmail.com

> On 26 Oct 2016, at 04:44, Henrik Bengtsson <henrik.bengtsson at
gmail.com> wrote:
> .......
> This looks like a bug to me.  Can anyone on macOS confirm whether this
> is also a problem there or not?
> 

Tried it on macOS El Capitan and got this (running in R.app with R version 3.3.2
RC (2016-10-23 r71574):
> setTimeLimit(elapsed=1)
> system.time({ Sys.sleep(10); message("done") })
Error in Sys.sleep(10) : reached elapsed time limit
Timing stopped at: 0.113 0.042 10.038 

Berend

Thank you for the feedback and confirmations.  Interesting to see that
it's also reproducible on macOS expect for Spencer; that might
indicate a difference in builds.

BTW, my original post suggested that timeout error was for sure
detected while running Sys.sleep(10).  However, it could of course
also be that it is only detected after it finishes.


For troubleshooting, the help("setTimeLimit", package =
"base") says that:

* "Time limits are checked whenever a user interrupt could occur. This
will happen frequently in R code and during Sys.sleep, but only at
points in compiled C and Fortran code identified by the code author."

The example here uses Sys.sleep(), which supports and detects user interrupts.


The timeout error message is thrown by the R_ProcessEvents(void)
function as defined in:

* src/unix/sys-unix.c
(https://github.com/wch/r-source/blob/trunk/src/unix/sys-unix.c#L421-L453)
* src/gnuwin32/system.c
(https://github.com/wch/r-source/blob/trunk/src/gnuwin32/system.c#L110-L140)

So, they're clearly different implementations on Windows and Unix.
Also, for the Unix implementation, the code differ based on
preprocessing directive HAVE_AQUA, which could explain why Spencer
observes a different behavior than Peter and Berend (all on macOS).


Whenever the R_CheckUserInterrupt() function is called it in turn
always calls R_ProcessEvents().  At the end, there is a code snippet -
if (R_interrupts_pending) onintr(); - which is Windows specific and
could be another important difference between Windows and Unix.  This
function is defined in:

* src/main/errors.c
(https://github.com/wch/r-source/blob/trunk/src/main/errors.c#L114-L134)


The do_setTimeLimit() function controls global variables cpuLimitValue
and elapsedLimitValue, which are checked in R_ProcessEvents(), but
other than setting the timeout limits I don't think it's involved in
the runtime checks. The do_setTimeLimit() is defined in:

* src/main/sysutils.c
(https://github.com/wch/r-source/blob/trunk/src/main/sysutils.c#L1692-L1736)


Unfortunately, right now, I've got little extra time to troubleshoot
this further.

/Henrik

On Wed, Oct 26, 2016 at 2:22 AM, Berend Hasselman <bhh at xs4all.nl>
wrote:
>
>> On 26 Oct 2016, at 04:44, Henrik Bengtsson <henrik.bengtsson at
gmail.com> wrote:
>> .......
>> This looks like a bug to me.  Can anyone on macOS confirm whether this
>> is also a problem there or not?
>>
>
>
> Tried it on macOS El Capitan and got this (running in R.app with R version
3.3.2 RC (2016-10-23 r71574):
>
>> setTimeLimit(elapsed=1)
>> system.time({ Sys.sleep(10); message("done") })
> Error in Sys.sleep(10) : reached elapsed time limit
> Timing stopped at: 0.113 0.042 10.038
>
> Berend
>