From mboxrd@z Thu Jan 1 00:00:00 1970 From: John Hendy Subject: Re: Bug? R: Org babel block execution *drastically* slower than in ESS session directly Date: Thu, 1 Nov 2012 09:53:51 -0500 Message-ID: References: <874nlappb1.fsf@tajo.ucsd.edu> <878vam1jvh.fsf@tajo.ucsd.edu> <3477.1351723988@alphaville> Mime-Version: 1.0 Content-Type: multipart/alternative; boundary=bcaec51f9555f849db04cd702fb4 Return-path: Received: from eggs.gnu.org ([208.118.235.92]:36202) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1TTw9c-0002BK-Lu for emacs-orgmode@gnu.org; Thu, 01 Nov 2012 10:54:00 -0400 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1TTw9Z-0006HT-36 for emacs-orgmode@gnu.org; Thu, 01 Nov 2012 10:53:56 -0400 Received: from mail-ob0-f169.google.com ([209.85.214.169]:33534) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1TTw9Y-0006GV-S3 for emacs-orgmode@gnu.org; Thu, 01 Nov 2012 10:53:53 -0400 Received: by mail-ob0-f169.google.com with SMTP id va7so2904640obc.0 for ; Thu, 01 Nov 2012 07:53:51 -0700 (PDT) In-Reply-To: <3477.1351723988@alphaville> List-Id: "General discussions about Org-mode." List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: emacs-orgmode-bounces+geo-emacs-orgmode=m.gmane.org@gnu.org Sender: emacs-orgmode-bounces+geo-emacs-orgmode=m.gmane.org@gnu.org To: nicholas.dokos@hp.com Cc: emacs-orgmode@gnu.org, cberry@tajo.ucsd.edu --bcaec51f9555f849db04cd702fb4 Content-Type: text/plain; charset=UTF-8 On Wed, Oct 31, 2012 at 5:53 PM, Nick Dokos wrote: > John Hendy wrote: > > > On Wed, Oct 31, 2012 at 3:12 PM, wrote: > > > > John Hendy writes: > > > > > On Wed, Oct 31, 2012 at 11:41 AM, cberry@tajo.ucsd.edu> wrote: > > > John Hendy writes: > > > > > >> I edited the subject to be more concise/clear.I let orgmode chug > away > > >> on reading in some ~10-30mb csv files for nearly 30min. > > > > > > [rest deleted] > > > > > > You need an ECM.I did my best to provide one, other than the file, > which I offered to provide > > if others requested that I upload it somewhere. Since you have done > so, so have I: > > > - https://docs.google.com/open?id=0BzQupOSnvw08WHdabHh5VVczRGM > > > > > Let me know if that doesn't work. I put it on Google docs and > sometimes have issues with > > the sharing settings... > > > > Not an ECM in my book, but ... > > > > What else would you like? I provided: > > - the config > > - the data > > - how to [attempt to] reproduce > > - the org-mode text > > > > Smaller set of data I'd guess :-) But it does not seem to be the > size of the data that matters. > > > > > > > On my 4 year old MacBook: > > > > ,---- > > | > > | #+PROPERTY: session *R* > > | > > | #+name: bigcsv > > | #+begin_src R > > | bigcsv <- Sys.glob("~/Downloads/*.csv") > > | #+end_src > > | > > | #+RESULTS: bigcsv > > | : /Users/cberry/Downloads/test-file.csv > > | > > | #+name: readbig > > | #+begin_src R :results output > > | system.time( > > | tmp <- read.csv(bigcsv) > > | ) > > | > > | #+end_src > > | > > | #+RESULTS: readbig > > | : user system elapsed > > | : 5.679 0.306 6.002 > > | > > `---- > > > > About the same as running from ESS. > > > > Not sure what to say. Looking for ways to troubleshoot or confirm. Since > you can't confirm, any > > suggestions on where I should look for my issue? I can't explain it! All > I know is that org chugs > > and chugs and the direct execution in ESS session is lightning fast. > > > > A few things to try in no particular order: > > This was extremely helpful. Thanks for the suggestions. Here's my attempt at an ECM, though I'm going to keep using the big file since that's what's actually doing it an I've already uploaded it :) - Using emacs config here: http://pastebin.com/raw.php?i=iTbRtCE9 - Using this org-mode file: #+begin_src org * headline #+begin_src R :session r :results silent # file here: https://docs.google.com/uc?export=download&confirm=no_antivirus&id=0BzQupOSnvw08WHdabHh5VVczRGM data <- read.csv("path/to/file.csv") #+end_src #+end_src org - Execute block with C-c C-c after downloading and changing path o run top (or whatever equivalent is available on your OS) and see > whether the CPU (or one of the CPUs) gets pegged at 100% utilization > and stays there. If yes, that's an indication of an infinite loop > somewhere. > > - quit any other instances of emacs/R - start `top` in terminal - execute block - Use '<' '>' to sort back and forth between cpu and ram Observations - R is at 80-100% cpu for about 5sec - Then emacs shifts to fairly constant ~100% cpu usage - After about a minute, the minibuffer expands to ~1/3 of the window height and fills with the csv data - Finished after ~5min total time - So, R took about 5sec, emacs took another 5min to finish > o run vmstat (or equivalent) and see if any of the counters are out of > whack. > That requires some experience though. > > I'll skip for now; no experience with that. > o use elp-instrument-package to instrument org and run the test, getting > a profile. I'm not sure whether the results will be useful, since you > are going to interrupt the test when you run out of patience, but it > cannot hurt and it might tell you something useful. > > o run your ECM on a different computer/OS/emacs installation. Being able > to compare things side by side is often very useful. > > o Halve your file and run the test on each half (but that's probably not > the problem given Chuck's results). > > o Reinstall org from scratch - you might have some corruption in one of > the compiled files that's causing it to go into an infinite loop. > > - `cd ~/.elisp` - `sudo rm -r org.git` - `git clone http://git://orgmode.org/org-mode.git org.git` - cd org.git && make clean && make && make doc - Quit previous emacs instance; reopen - Remove (require 'org-install) per prompt; restart again - Repeat `top` experiment Results: - Didn't even see R flash on the screen this time; emacs just jumped to 100% - After 1min 10sec, the minibuffer filled with data - At that point I quit, as I think it will be a repeat of the above > o Turn on debug-on-quit, start your test, wait a bit and then interrupt > it. Check the backtrace. Do it again and check whether the backtrace > looks the same. That's often an indication of an infinite loop > (inferring an infinite loop from a two element sample is statistically > suspect of course, but surprisingly effective nevertheless). The point > here is that the infinite loop is in emacs and the backtrace tells you > something about the parties involved. > > - =M-x customize-variable RET debug-on-quit RET= - Toggled to on; saved for current session - Waited about a min (till the minibuffer filled), then did C-g Don't have experience with debugging. It brings me to a *Backtrace* buffer, which is empty except for the line "Debugger entered--Lisp error: (quit)" Thanks for the suggestions and help. That was quite above and beyond. Much appreciated. Best regards, John These are obviously not independent and the results of one experiment will > have to guide you in what you try next. > > Good luck, > Nick > --bcaec51f9555f849db04cd702fb4 Content-Type: text/html; charset=UTF-8 Content-Transfer-Encoding: quoted-printable On Wed, Oct 31, 2012 at 5:53 PM, Nick Dokos <nicholas.dokos@hp.com> wrote:
John Hendy <jw.hendy@gmail.com> wrote:

> On Wed, Oct 31, 2012 at 3:12 PM, <cberry@tajo.ucsd.edu> wrote:
>
> =C2=A0 =C2=A0 John Hendy <jw.hendy@gmail.com> writes:
>
> =C2=A0 =C2=A0 > On Wed, Oct 31, 2012 at 11:41 AM, =C2=A0<span di= r=3D"ltr"><mailto:cberry@tajo.ucsd.edu></span> wrote:
> =C2=A0 =C2=A0 > John Hendy <mailto:jw.hendy@gmail.com> writes:
> =C2=A0 =C2=A0 >
> =C2=A0 =C2=A0 >> I edited the subject to be more concise/clear.I= let orgmode chug away
> =C2=A0 =C2=A0 >> on reading in some ~10-30mb csv files for nearl= y 30min.
> =C2=A0 =C2=A0 >
> =C2=A0 =C2=A0 > [rest deleted]
> =C2=A0 =C2=A0 >
> =C2=A0 =C2=A0 > You need an ECM.I did my best to provide one, other= than the file, which I offered to provide
> =C2=A0 =C2=A0 if others requested that I upload it somewhere. Since yo= u have done so, so have I:
> =C2=A0 =C2=A0 > -=C2=A0https://docs.google.com/= open?id=3D0BzQupOSnvw08WHdabHh5VVczRGM
>
> =C2=A0 =C2=A0 > Let me know if that doesn&#39;t work. I put it = on Google docs and sometimes have issues with
> =C2=A0 =C2=A0 the sharing settings...
>
> =C2=A0 =C2=A0 Not an ECM in my book, but ...
>
> What else would you like? I provided:
> - the config
> - the data
> - how to [attempt to] reproduce
> - the org-mode text
>

Smaller set of data I'd guess :-) But it does not seem to be the<= br> size of the data that matters.

> =C2=A0
>
> =C2=A0 =C2=A0 On my 4 year old MacBook:
>
> =C2=A0 =C2=A0 ,----
> =C2=A0 =C2=A0 |
> =C2=A0 =C2=A0 | #+PROPERTY: session *R*
> =C2=A0 =C2=A0 |
> =C2=A0 =C2=A0 | #+name: bigcsv
> =C2=A0 =C2=A0 | #+begin_src R
> =C2=A0 =C2=A0 | bigcsv <- Sys.glob("~/Downloads/*.csv") > =C2=A0 =C2=A0 | #+end_src
> =C2=A0 =C2=A0 |
> =C2=A0 =C2=A0 | #+RESULTS: bigcsv
> =C2=A0 =C2=A0 | : /Users/cberry/Downloads/test-file.csv
> =C2=A0 =C2=A0 |
> =C2=A0 =C2=A0 | #+name: readbig
> =C2=A0 =C2=A0 | #+begin_src R :results output
> =C2=A0 =C2=A0 | =C2=A0 system.time(
> =C2=A0 =C2=A0 | =C2=A0 =C2=A0 tmp <- read.csv(bigcsv)
> =C2=A0 =C2=A0 | =C2=A0 =C2=A0 )
> =C2=A0 =C2=A0 |
> =C2=A0 =C2=A0 | #+end_src
> =C2=A0 =C2=A0 |
> =C2=A0 =C2=A0 | #+RESULTS: readbig
> =C2=A0 =C2=A0 | : =C2=A0 =C2=A0user =C2=A0system elapsed
> =C2=A0 =C2=A0 | : =C2=A0 5.679 =C2=A0 0.306 =C2=A0 6.002
> =C2=A0 =C2=A0 |
> =C2=A0 =C2=A0 `----
>
> =C2=A0 =C2=A0 About the same as running from ESS.
>
> Not sure what to say. Looking for ways to troubleshoot or confirm. Sin= ce you can't confirm, any
> suggestions on where I should look for my issue? I can't explain i= t! All I know is that org chugs
> and chugs and the direct execution in ESS session is lightning fast. >

A few things to try in no particular order:


This was extremely helpful. Thanks for= the suggestions.

Here's my attempt at an ECM,= though I'm going to keep using the big file since that's what'= s actually doing it an I've already uploaded it :)
- Using emacs config here:=C2=A0http://pastebin.com/raw.php?i=3DiTbRtCE9


* headline

#+begin_src R :session r :res= ults silent
data <- read.csv("path/to/file.csv")
#+end_src<= /div>

#+end_src org
=C2=A0
- E= xecute block with C-c C-c after downloading and changing path
o run top (or whatever equivalent is available on your OS) and see
=C2=A0 whether the CPU (or one of the CPUs) gets pegged at 100% utilization=
=C2=A0 and stays there. If yes, that's an indication of an infinite loo= p
=C2=A0 somewhere.


- quit any other instances of emacs/R<= /div>
- start `top` in terminal
- execute block
- U= se '<' '>' to sort back and forth between cpu and ram=

Observations
- R is at 80-100% cpu for about = 5sec
- Then emacs shifts to fairly constant ~100% cpu usage=C2=A0=
- After about a minute, the minibuffer expands to ~1/3 of the wi= ndow height and fills with the csv data
- Finished after ~5min total time
- So, R took about 5sec, e= macs took another 5min to finish
=C2=A0
o run vmstat (or equivalent) and see if any of the counters are out of whac= k.
=C2=A0 That requires some experience though.


I'll skip for now; no experience w= ith that.
=C2=A0
o use elp-instrument-package to instrument org and run the test, getting =C2=A0 a profile. I'm not sure whether the results will be useful, sinc= e you
=C2=A0 are going to interrupt the test when you run out of patience, but it=
=C2=A0 cannot hurt and it might tell you something useful.

o run your ECM on a different computer/OS/emacs installation. Being able =C2=A0 to compare things side by side is often very useful.

o Halve your file and run the test on each half (but that's probably no= t
=C2=A0 the problem given Chuck's results).

o Reinstall org from scratch - you might have some corruption in one of
=C2=A0 the compiled files that's causing it to go into an infinite loop= .


- `cd ~/.elisp`
- `sudo rm -= r org.git`
- `git clone http://git://orgmode.org/org-mode.git org.git`
- cd org.git && make clean && make && make doc=
- Quit previous emacs instance; reopen
- Remove (require = 9;org-install) per prompt; restart again
- Repeat `top` experimen= t

Results:
- Didn't even see R flash= on the screen this time; emacs just jumped to 100%
- After 1min 10sec, the minibuffer filled with data
- At tha= t point I quit, as I think it will be a repeat of the above
=C2= =A0
o Turn on debug-on-quit, start your test, wait a bit and then interrupt
=C2=A0 it. Check the backtrace. =C2=A0Do it again and check whether the bac= ktrace
=C2=A0 looks the same. That's often an indication of an infinite loop =C2=A0 (inferring an infinite loop from a two element sample is statistical= ly
=C2=A0 suspect of course, but surprisingly effective nevertheless). The poi= nt
=C2=A0 here is that the infinite loop is in emacs and the backtrace tells y= ou
=C2=A0 something about the parties involved.


- =3DM-x customize-variable RET debug-= on-quit RET=3D
- Toggled to on; saved for current session
- Waited about a min (till the minibuffer filled), then did C-g

Don't have experience with debugging. It brings me to a = *Backtrace* buffer, which is empty except for the line "Debugger enter= ed--Lisp error: (quit)"
=C2=A0
Thanks for the sugg= estions and help. That was quite above and beyond. Much appreciated.


Best regards,
John
<= br>
These are obviously not independent and the results of one experiment will<= br> have to guide you in what you try next.

Good luck,
Nick

--bcaec51f9555f849db04cd702fb4--