Skip to content

[Rcpp-devel] Rcpp Timer

7 messages · Kaspar Märtens, Jonathan Christensen, Dirk Eddelbuettel +1 more

Kaspar Märtens
# 
Hi,

Trying out the Rcpp Timer example from
http://gallery.rcpp.org/articles/using-the-rcpp-timer/ I was unable to
reproduce similar results. The example output

    get/put g/p+rnorm()  empty loop
  1.967e+03   3.288e+03   6.400e-04

compared to the output I see

    get/put g/p+rnorm()  empty loop
   733.5265   1884.9589   1884.9601

Suspiciously, the empty loop appears to take the longest. Could these be
cumulatively measured times here?

Best,
Kaspar
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.r-forge.r-project.org/pipermail/rcpp-devel/attachments/20161229/2977053f/attachment.html>
Dirk Eddelbuettel
#
On 29 December 2016 at 14:55, Kaspar M?rtens wrote:
| Hi,?
| 
| Trying out the Rcpp Timer example from?http://gallery.rcpp.org/articles/
| using-the-rcpp-timer/ I was unable to reproduce similar results. The example
| output
| 
| ? ? get/put g/p+rnorm() ?empty loop?
| ? 1.967e+03 ? 3.288e+03 ? 6.400e-04?
| 
| compared to the output I see
| 
| ? ? get/put g/p+rnorm() ?empty loop
| ? ?733.5265 ? 1884.9589 ? 1884.9601
| 
| Suspiciously, the empty loop appears to take the longest. Could these be
| cumulatively measured times here??

It is possibly that there is a thinko / bug / error somewhere.  I just re-ran
it via sourceCpp() [ see below ] which is pretty much what Ruby + Jekyll do
to build the Rcpp Gallery pages.

The results will reflect the underlying machines a little but the difference
you show is much starker.  What is your OS / compiler?   Ubuntu 16.04 with
g++-5.3 here; page was original written with an older g++.

Dirk


Copy and paste below (and I just removed two lines pertaining to ESS which do
no matter here).

R version 3.3.2 (2016-10-31) -- "Sincere Pumpkin Patch"
Copyright (C) 2016 The R Foundation for Statistical Computing
Platform: x86_64-pc-linux-gnu (64-bit)

R is free software and comes with ABSOLUTELY NO WARRANTY.
You are welcome to redistribute it under certain conditions.
Type 'license()' or 'licence()' for distribution details.

  Natural language support but running in an English locale

R is a collaborative project with many contributors.
Type 'contributors()' for more information and
'citation()' on how to cite R or R packages in publications.

Type 'demo()' for some demos, 'help()' for on-line help, or
'help.start()' for an HTML browser interface to help.
Type 'q()' to quit R.

R> library(Rcpp)
R> sourceCpp("~/git/rcpp-gallery/src/2013-01-06-using-the-rcpp-timer.cpp")

R> useTimer()
    get/put g/p+rnorm()  empty loop 
    1620.67     3973.43     3973.44 
R>
Jonathan Christensen
# 
Hi Kaspar and Dirk,

It is indeed cumulative. Previously (presumably when that gallery page was
written) it was not cumulative, but Romain Francois changed the behavior of
the step() function several years ago, in this commit:
https://github.com/RcppCore/Rcpp/commit/e295b2b178de55291e63705966368404bb0ce5e1
.

There is no indication or reasoning about changing the behavior, so it may
be that making it cumulative was unintentional.

Jonathan
On Thu, Dec 29, 2016 at 8:23 AM, Dirk Eddelbuettel <edd at debian.org> wrote:

            

      
      
      
    

        

      
      
    

        
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.r-forge.r-project.org/pipermail/rcpp-devel/attachments/20161229/251b0318/attachment.html>

  
  


  


      

    

    

      
      

        


  

        

      Dirk Eddelbuettel
    

    

      
      #
    

  


  

      
On 29 December 2016 at 11:25, Jonathan Christensen wrote:

        
| Hi Kaspar and Dirk,
| 
| It is indeed cumulative. Previously (presumably when that gallery page was
| written) it was not cumulative, but Romain Francois changed the behavior of the
| step() function several years ago, in this commit:?https://github.com/RcppCore/
| Rcpp/commit/e295b2b178de55291e63705966368404bb0ce5e1.

Nice catch.
 
| There is no indication or reasoning about changing the behavior, so it may be
| that making it cumulative was unintentional.

Let's presume it was intentional to the author of the change -- but as you
rightly point out, it did of course change and reverse previous behaviour.

We could easily add a toggle to the constructor to get an either/or behaviour.

Dirk

  
    

      
      
    

  


  


      

    

    

      
      

        


  

        

      Dirk Eddelbuettel
    

    

      
      #
    

  


  

      
On 30 December 2016 at 06:37, Dirk Eddelbuettel wrote:

        
|

        
| On 29 December 2016 at 11:25, Jonathan Christensen wrote:

        
| | Hi Kaspar and Dirk,
| | 
| | It is indeed cumulative. Previously (presumably when that gallery page was
| | written) it was not cumulative, but Romain Francois changed the behavior of the
| | step() function several years ago, in this commit:?https://github.com/RcppCore/
| | Rcpp/commit/e295b2b178de55291e63705966368404bb0ce5e1.
| 
| Nice catch.
|  
| | There is no indication or reasoning about changing the behavior, so it may be
| | that making it cumulative was unintentional.
| 
| Let's presume it was intentional to the author of the change -- but as you
| rightly point out, it did of course change and reverse previous behaviour.
| 
| We could easily add a toggle to the constructor to get an either/or behaviour.

Even easier:
    - Add a step() call immediately after creating timer()
    - This also records the start
    - Results are still cumulative
    - Running diff() over it shows changes:

Demo using minimally modified Rcpp Gallery piece (just added step("start"); )

    R> sourceCpp("/tmp/timer.cpp")

    R> tt <- useTimer()

    R> tt         # cumulative
          start     get/put g/p+rnorm()  empty loop 
       0.000114 1629.043000 3996.890739 3996.893329 

    R> diff(tt)   # incremental
        get/put g/p+rnorm()  empty loop 
     1629.04289  2367.84774     0.00259 
    R>

I will alter the gallery story accordingly. We can always add a 'zero' step
to the constructor to get these two behaviours cheaply.

Dirk

  
    

      
      
    

  


  


      

    

    

      
      

        


  

        

      Romain Francois
    

    

      
      #
    

  


  

      
It made more sense to track times since an origin, esp when you might use several timers in case you use multiple threads.

            

      
      
      
    

        

      
      
    

  
  


  


      

    

    

      
      

        


  

        

      Dirk Eddelbuettel
    

    

      
      #
    

  


  

      
On 30 December 2016 at 20:38, Romain Francois wrote:

        
| It made more sense to track times since an origin, esp when you might use several timers in case you use multiple threads. 

Using an offset to an origin (and hence differences) is also a sensible way
to deal with higher resolutions.  We cannot natively represent nanoseconds
(which the Timer class uses) in R with base types: doubles use 53 bits
precision which gets us a bit more than microseconds, and ints are 32 bit --
so conversion would be lossy.  (The nanoseconds package I just releases uses
bit64::integer64 which gets us nanosecond, but that is a higher-level depend
and not something we want to depend on at the Rcpp level).

Whether cumulative times, or individual measurements is better is still open
fore debate.  In any event, I fixed the Rcpp Gallery story at

    http://gallery.rcpp.org/articles/using-the-rcpp-timer/

Dirk
 
| > Le 30 d?c. 2016 ? 13:37, Dirk Eddelbuettel <edd at debian.org> a ?crit :
| > 
| >

        
| > On 29 December 2016 at 11:25, Jonathan Christensen wrote:

        
| > | Hi Kaspar and Dirk,
| > | 
| > | It is indeed cumulative. Previously (presumably when that gallery page was
| > | written) it was not cumulative, but Romain Francois changed the behavior of the
| > | step() function several years ago, in this commit: https://github.com/RcppCore/
| > | Rcpp/commit/e295b2b178de55291e63705966368404bb0ce5e1.
| > 
| > Nice catch.
| > 
| > | There is no indication or reasoning about changing the behavior, so it may be
| > | that making it cumulative was unintentional.
| > 
| > Let's presume it was intentional to the author of the change -- but as you
| > rightly point out, it did of course change and reverse previous behaviour.
| > 
| > We could easily add a toggle to the constructor to get an either/or behaviour.
| > 
| > Dirk
| > 
| > -- 
| > http://dirk.eddelbuettel.com | @eddelbuettel | edd at debian.org
| > _______________________________________________
| > Rcpp-devel mailing list
| > Rcpp-devel at lists.r-forge.r-project.org
| > https://lists.r-forge.r-project.org/cgi-bin/mailman/listinfo/rcpp-devel
|