Hi : I looked at the help for system.time but I still have the following question. Can someone explain the output following output of system.time : user system elapsed 12399.681 5632.352 56935.647 Here's my take based on the fact that I was doing ps -aux | grep R off and on and the total amount of CPU minutes that got allotted before the job ended was about 5 hours and the total actual time that the job took was about 15 hours. Does elapsed = total actual time job taken ? That seems to be the case or a strange coincidence. Does user + system = CPU time from ps -aux | grep R ? That seems to be the case also or a weird coincidence. Finally, why can't the CPU get a higher percentage ? It's seems like it's always around 30% which would make sense since 5 is ~ 30% of 15 hours. Also, assuming my take above is correct, when talking about timing of algorithms, in this case, does one say the job took 5 hours or 15 hours ? I'm trying to see how fast an algorithm is compared to others and I'm not sure what the standard is. I'm on fedora 16.0 and using R 2.15. Thanks. [[alternative HTML version deleted]]
You asked several questions. Elapsed: yes User + System = CPU: yes Finally: You have to look at the load and/or cpu core count. Unless you setup your code to take advantage of multiple cores, R runs on a single core. Also: Do you really need to ask that question? --------------------------------------------------------------------------- Jeff Newmiller The ..... ..... Go Live... DCN:<jdnewmil at dcn.davis.ca.us> Basics: ##.#. ##.#. Live Go... Live: OO#.. Dead: OO#.. Playing Research Engineer (Solar/Batteries O.O#. #.O#. with /Software/Embedded Controllers) .OO#. .OO#. rocks...1k --------------------------------------------------------------------------- Sent from my phone. Please excuse my brevity. Mark Leeds <markleeds2 at gmail.com> wrote:>Hi : I looked at the help for system.time but I still have the >following >question. Can someone explain the output following output >of system.time : > > user system elapsed >12399.681 5632.352 56935.647 > >Here's my take based on the fact that I was doing ps -aux | grep R off >and >on and the total amount of CPU minutes that >got allotted before the job ended was about 5 hours and the total >actual >time that the job took was about 15 hours. > >Does elapsed = total actual time job taken ? That seems to be the case >or a >strange coincidence. > >Does user + system = CPU time from ps -aux | grep R ? That seems to be >the >case also or a weird coincidence. > >Finally, why can't the CPU get a higher percentage ? It's seems like >it's >always around 30% which would make sense since >5 is ~ 30% of 15 hours. > >Also, assuming my take above is correct, when talking about timing of >algorithms, in this case, does one say the job took 5 hours or 15 hours >? >I'm trying to see how fast an algorithm is compared to others and I'm >not >sure what the standard is. I'm on fedora 16.0 and using R 2.15. >Thanks. > > [[alternative HTML version deleted]] > >______________________________________________ >R-help at r-project.org mailing list >https://stat.ethz.ch/mailman/listinfo/r-help >PLEASE do read the posting guide >http://www.R-project.org/posting-guide.html >and provide commented, minimal, self-contained, reproducible code.
On 20/10/2012 17:16, Mark Leeds wrote:> Hi : I looked at the help for system.time but I still have the following > question. Can someone explain the output following output > of system.time : > > user system elapsed > 12399.681 5632.352 56935.647Yes, the help page can, via ?proc.time. As it says, it depends on the OS> Here's my take based on the fact that I was doing ps -aux | grep R off and > on and the total amount of CPU minutes that > got allotted before the job ended was about 5 hours and the total actual > time that the job took was about 15 hours. > > Does elapsed = total actual time job taken ? That seems to be the case or a > strange coincidence. > > Does user + system = CPU time from ps -aux | grep R ? That seems to be the > case also or a weird coincidence.On Fedora Linux, yes. Not in general (and what ps gives is pretty OS-specific: for example, does it include time from child processes or not -- system.time should but the OS calls used do not always do so, I find less reliably so in Fedora 16 than 14).> Finally, why can't the CPU get a higher percentage ? It's seems like it's > always around 30% which would make sense since > 5 is ~ 30% of 15 hours.Many, many reasons. Most likely - other things are running, and some of them have a higher priority, or equal or lower priority and get lots of time slices .... - R the process is waiting for resources, such as memory, discs, network access ....> Also, assuming my take above is correct, when talking about timing of > algorithms, in this case, does one say the job took 5 hours or 15 hours ? > I'm trying to see how fast an algorithm is compared to others and I'm not > sure what the standard is. I'm on fedora 16.0 and using R 2.15. Thanks.It depends on the purpose. CRAN's check farm cares most about CPU usage: someone waiting for results cares about elapsed time.> > [[alternative HTML version deleted]] > > ______________________________________________ > R-help at r-project.org mailing list > https://stat.ethz.ch/mailman/listinfo/r-help > PLEASE do read the posting guide http://www.R-project.org/posting-guide.html > and provide commented, minimal, self-contained, reproducible code. >-- Brian D. Ripley, ripley at stats.ox.ac.uk Professor of Applied Statistics, http://www.stats.ox.ac.uk/~ripley/ University of Oxford, Tel: +44 1865 272861 (self) 1 South Parks Road, +44 1865 272866 (PA) Oxford OX1 3TG, UK Fax: +44 1865 272595
Others have said what system time is, time spent in the kernel of the operating system doing things on behalf of your program. Also, switching between user and system mode can be time consuming, so the number of system calls can be important, even if each one takes little time. I don't know how the time it takes to switch is reported - is it user, system or just elapsed time. In my experience, a big system time that is a red flag and you can usually get rid of most of it. Often, reducing the system time decreases the user time as well. In many cases it is due to opening files and writing to or reading from files. E.g., define a function, f, that append a few lines to a file: f <- function (filename) cat(file = filename, append = TRUE, 1:4, sep = "\n") Use system.time to time it on a file in /tmp: > tf <- "/tmp/junk.txt" > unlink(tf) ; system.time(for(i in 1:10000)f(tf)) user system elapsed 0.752 0.216 0.967 The system time is a quarter of the user time. One way of reducing that time is to open the file once, write to it many times, then close it. (Opening a file is time consuming because it needs to be found.) > unlink(tf) ; tfo <- file(tf, open="w") ; system.time(for(i in 1:10000)f(tfo)) ; close(tfo) user system elapsed 0.128 0.100 0.227 The system/user ratio is still high, but all the times are smaller. Here is an example of the waiting for a resource problem that Brian Ripley mentioned. I use the same function, f, but I use it on a file in my home directory, which is on a file server. (/tmp is of type 'tmpfs, which I think means it is not even on a disk.) > mf <- "/homes/bill/junk.txt" > unlink(mf) ; system.time(for(i in 1:10000)f(mf)) user system elapsed 1.476 1.208 41.532 The huge elapsed time it due to the kernel waiting for the file server to find /homes/bill/junk.txt, over and over again. Open it once and the times are more in line with using /tmp: > unlink(mf) ; mfo <- file(mf, open="w") ; system.time(for(i in 1:10000)f(mfo)) ; close(mfo) user system elapsed 0.140 0.044 0.186 On Linux you can use the strace command to see what system calls R is making while your program runs. Get the process identifier from Sys.getpid() and run strace in a different window. E.g., % strace -T -p 24197 | & head -100 ... lots of repetitions of the following sequence: open("/homes/bill/junk.txt", O_WRONLY|O_CREAT|O_APPEND, 0666) = 3 <0.003782> fstat(3, {st_mode=S_IFREG|0664, st_size=0, ...}) = 0 <0.000037> mmap(NULL, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9ffae4b000 <0.000038> fstat(3, {st_mode=S_IFREG|0664, st_size=0, ...}) = 0 <0.000078> lseek(3, 0, SEEK_SET) = 0 <0.000011> write(3, "1", 1) = 1 <0.000087> write(3, "\n", 1) = 1 <0.000088> write(3, "2", 1) = 1 <0.000014> write(3, "\n", 1) = 1 <0.000010> write(3, "3", 1) = 1 <0.000011> write(3, "\n", 1) = 1 <0.000010> write(3, "4", 1) = 1 <0.000010> write(3, "\n", 1) = 1 <0.000009> close(3) = 0 <0.001938> munmap(0x7f9ffae4b000, 65536) = 0 <0.000032> open("/homes/bill/junk.txt", O_WRONLY|O_CREAT|O_APPEND, 0666) = 3 <0.003711> ... The times are shown in <>. Bill Dunlap Spotfire, TIBCO Software wdunlap tibco.com> -----Original Message----- > From: r-help-bounces at r-project.org [mailto:r-help-bounces at r-project.org] On Behalf > Of Mark Leeds > Sent: Saturday, October 20, 2012 9:16 AM > To: R help > Subject: [R] system.time question > > Hi : I looked at the help for system.time but I still have the following > question. Can someone explain the output following output > of system.time : > > user system elapsed > 12399.681 5632.352 56935.647 > > Here's my take based on the fact that I was doing ps -aux | grep R off and > on and the total amount of CPU minutes that > got allotted before the job ended was about 5 hours and the total actual > time that the job took was about 15 hours. > > Does elapsed = total actual time job taken ? That seems to be the case or a > strange coincidence. > > Does user + system = CPU time from ps -aux | grep R ? That seems to be the > case also or a weird coincidence. > > Finally, why can't the CPU get a higher percentage ? It's seems like it's > always around 30% which would make sense since > 5 is ~ 30% of 15 hours. > > Also, assuming my take above is correct, when talking about timing of > algorithms, in this case, does one say the job took 5 hours or 15 hours ? > I'm trying to see how fast an algorithm is compared to others and I'm not > sure what the standard is. I'm on fedora 16.0 and using R 2.15. Thanks. > > [[alternative HTML version deleted]] > > ______________________________________________ > R-help at r-project.org mailing list > https://stat.ethz.ch/mailman/listinfo/r-help > PLEASE do read the posting guide http://www.R-project.org/posting-guide.html > and provide commented, minimal, self-contained, reproducible code.