You could run proc.time() before and after each system call.
x <- proc.time()
# do something
y <- proc.time()
y - x
On Fri, Jun 12, 2009 at 5:31 PM, Andrew Piskorski<a...@piskorski.com> wrote:
> Rprof seems to ignore all time spent inside system() calls. E.g.,
> this simple example actually takes about 10 seconds, but Rprof thinks
> the total time is only 0.12 seconds:
>
>> Rprof("sleep-system.out") ; system.time(system(command="sleep 10")) ;
>> Rprof(NULL)
> user system elapsed
> 0.000 0.004 10.015
>> summaryRprof("sleep-system.out")$by.total
> total.time total.pct self.time self.pct
> "gc" 0.12 100 0.12 100
> "system.time" 0.12 100 0.00 0
>>
>
> I assume that what's going on here, is that anytime R blocks waiting
> for data from a child process, the profiler stops running entirley,
> and it then loses track of all that time spend blocking.
>
> This Rprof behavior is frustrating, because I use a database access
> layer which essentially works by having R call system() to run a shell
> script. So, if I write a really slow query that takes 10 minutes to
> run, as for as Rprof is concerned, those 10 minutes never happened,
> the query consumed zero time. In complicated code, this makes it much
> harder to figure out what parts are slow due to slow R code vs. slow
> SQL queries.
>
> Why does Rprof behave this way? Is there something I can do to
> work-around or alleviate this? What do you think it would take to fix
> Rprof to track the time spent waiting for system() to finish, and
> where in the R source should I look to attempt that?
>
> Thanks!
>
> --
> Andrew Piskorski <a...@piskorski.com>
> http://www.piskorski.com/
>
> ______________________________________________
> R-devel@r-project.org mailing list
> https://stat.ethz.ch/mailman/listinfo/r-devel
>
______________________________________________
R-devel@r-project.org mailing list
https://stat.ethz.ch/mailman/listinfo/r-devel
