From simon.urbanek at r-project.org  Fri Aug 10 23:16:39 2012
From: simon.urbanek at r-project.org (Simon Urbanek)
Date: Fri, 10 Aug 2012 17:16:39 -0400
Subject: [Rd] [R] debug vs regular mode
In-Reply-To: <50256A23.6070904@fhcrc.org>
References: <50244E49.5000908@med.umich.edu>
	<81A9521D-15DA-4F07-A68E-21A1AF643053@comcast.net>
	<2145D1BE-BC07-4CF1-B23E-C27F7264E732@gmail.com>
	<502489CF.5060402@med.umich.edu> <50250BE4.7000704@gmail.com>
	<50250FE0.3050506@med.umich.edu> <50252D1F.3060003@gmail.com>
	<50254A16.8010009@med.umich.edu>
	<8D7C3107-1C92-4F2B-8BCB-7C505095F3A0@gmail.com>
	<50256A23.6070904@fhcrc.org>
Message-ID: <B74E89CC-D854-4851-8447-32FD411FFDBD@r-project.org>


On Aug 10, 2012, at 4:08 PM, Martin Morgan wrote:

> On 08/10/2012 12:04 PM, peter dalgaard wrote:
>> Not to spoil your fun, but this is getting a bit off-topic for R-help. If you wish to continue the debugging process in public, I think you should move to R-devel.
>> 
>> Also, it sounds like the problem is in the glmulti package, so you might want to involve its maintainer at some point.
> 
> 
> 
> actually valgrind complains a lot about rJava, though that can be confusing; the example reproduces, so amenable to investigation. glmulti doesn't have C code and the only unusual dependency is rJava
> 


Actually, this crashes is vanilla R (given low enough stack limit, e.g. ulimit -s 1024) - simply try

terms(as.formula("h~ X1*X2*X3*X4*X5*X6*X7*X8*X9*X10*X11*X12*X13*X14*X15*X16"))

which is what the code below runs. The problem is that it causes a very deep recursion so depending on the stack it will fail (interestingly, it will segfault in the call to R_CheckStack which is paradoxical :)). I think the proper fix would be to use iteration in StripTerm instead of recursion ...

Cheers,
Simon

FWIW Java is in general not easily traceable through valgrind, unfortunately, because it uses a lot of dirty tricks like JIT and other things. There are some hints in the valgrind FAQ 3.4, though.


> > sessionInfo()
> R version 2.15.1 Patched (2012-06-22 r59603)
> Platform: x86_64-unknown-linux-gnu (64-bit)
> 
> locale:
> [1] en_US.UTF-8
> 
> attached base packages:
> [1] stats     graphics  grDevices utils     datasets  methods   base
> 
> other attached packages:
> [1] glmulti_1.0.4 rJava_0.9-3
> 
> 
> Here's the stack trace starting a little below the top
> 
> #21190 0x00007ffff78b3b88 in Rf_usemethod (generic=0x9f0c80 "terms", obj=0xbcd040, call=0xbf6fb0, args=0x604d18, rho=0xbd9e70, callrho=0xbf88e8, defrho=0x1a873f0,
>    ans=0x7fffffffb1a8) at /home/mtmorgan/src/R-2-15-branch/src/main/objects.c:339
> 339		    *ans = applyMethod(t, sxp, matchedarg, rho, newrho);
> (gdb)
> #21189 0x00007ffff78b3009 in applyMethod (call=0xbca188, op=0xbf67f0, args=0xbdad30, rho=0xbd9e70, newrho=0xbca118) at /home/mtmorgan/src/R-2-15-branch/src/main/objects.c:125
> 125		ans = applyClosure(call, op, args, rho, newrho);
> (gdb)
> #21188 0x00007ffff784c574 in Rf_applyClosure (call=0xbca188, op=0xbf67f0, arglist=0xbdad30, rho=0xbd9e70, suppliedenv=0xbca118)
>    at /home/mtmorgan/src/R-2-15-branch/src/main/eval.c:859
> 859		PROTECT(tmp = eval(body, newrho));
> (gdb)
> #21187 0x00007ffff784b4b5 in Rf_eval (e=0xbf52e0, rho=0xbc8f30) at /home/mtmorgan/src/R-2-15-branch/src/main/eval.c:466
> 466		    tmp = PRIMFUN(op) (e, op, CDR(e), rho);
> (gdb)
> #21186 0x00007ffff784e12d in do_begin (call=0xbf52e0, op=0x610710, args=0xbee388, rho=0xbc8f30) at /home/mtmorgan/src/R-2-15-branch/src/main/eval.c:1413
> 1413		    s = eval(CAR(args), rho);
> (gdb)
> #21185 0x00007ffff784b4b5 in Rf_eval (e=0xbee3c0, rho=0xbc8f30) at /home/mtmorgan/src/R-2-15-branch/src/main/eval.c:466
> 466		    tmp = PRIMFUN(op) (e, op, CDR(e), rho);
> (gdb)
> #21184 0x00007ffff784ef32 in do_set (call=0xbee3c0, op=0x610908, args=0xbedbc8, rho=0xbc8f30) at /home/mtmorgan/src/R-2-15-branch/src/main/eval.c:1715
> 1715		    s = eval(CADR(args), rho);
> (gdb)
> #21183 0x00007ffff784b4b5 in Rf_eval (e=0xbedc70, rho=0xbc8f30) at /home/mtmorgan/src/R-2-15-branch/src/main/eval.c:466
> 466		    tmp = PRIMFUN(op) (e, op, CDR(e), rho);
> (gdb)
> #21182 0x00007ffff78b2979 in do_internal (call=0xbedc70, op=0x611620, args=0xbc9518, env=0xbc8f30) at /home/mtmorgan/src/R-2-15-branch/src/main/names.c:1228
> 1228	    ans = PRIMFUN(INTERNAL(fun)) (s, INTERNAL(fun), args, env);
> (gdb)
> #21181 0x00007ffff78acdea in do_termsform (call=0xbedf48, op=0x6329f0, args=0xbc9518, rho=0xbc8f30) at /home/mtmorgan/src/R-2-15-branch/src/main/model.c:838
> 838	    PROTECT(formula = EncodeVars(CAR(args)));
> (gdb)
> #21180 0x00007ffff78ac4e6 in EncodeVars (formula=0xbcd040) at /home/mtmorgan/src/R-2-15-branch/src/main/model.c:629
> 629			return EncodeVars(CADDR(formula));
> (gdb)
> #21179 0x00007ffff78ac5c5 in EncodeVars (formula=0xbcd2a8) at /home/mtmorgan/src/R-2-15-branch/src/main/model.c:641
> 641		    return CrossTerms(CADR(formula), CADDR(formula));
> (gdb)
> #21178 0x00007ffff78abafb in CrossTerms (left=0xbcd318, right=0xd7e338) at /home/mtmorgan/src/R-2-15-branch/src/main/model.c:459
> 459	    PROTECT(left = EncodeVars(left));
> (gdb)
> #21177 0x00007ffff78ac5c5 in EncodeVars (formula=0xbcd318) at /home/mtmorgan/src/R-2-15-branch/src/main/model.c:641
> 641		    return CrossTerms(CADR(formula), CADDR(formula));
> (gdb)
> #21176 0x00007ffff78abc24 in CrossTerms (left=0xbc5558, right=0x16b6e78) at /home/mtmorgan/src/R-2-15-branch/src/main/model.c:471
> 471	    return TrimRepeats(left);
> (gdb)
> #21175 0x00007ffff78ab934 in TrimRepeats (list=0xbc5558) at /home/mtmorgan/src/R-2-15-branch/src/main/model.c:404
> 404	    SETCDR(list, TrimRepeats(StripTerm(CAR(list), CDR(list))));
> (gdb)
> #21174 0x00007ffff78ab88d in StripTerm (term=0x121c1d8, list=0xbc5590) at /home/mtmorgan/src/R-2-15-branch/src/main/model.c:385
> 385	    tail = StripTerm(term, CDR(list));
> 
> and so on down to the bottom
> 
> valgrind says this
> 
> ==14352== Invalid write of size 4
> ==14352==    at 0xD4BC2BD: ???
> ==14352==    by 0xD4AC437: ???
> ==14352==    by 0xBDE21AE: JavaCalls::call_helper(JavaValue*, methodHandle*, JavaCallArguments*, Thread*) (in /usr/lib/jvm/java-7-openjdk-amd64/jre/lib/amd64/server/libjvm.so)
> ==14352==    by 0xBDE1A44: JavaCalls::call(JavaValue*, methodHandle, JavaCallArguments*, Thread*) (in /usr/lib/jvm/java-7-openjdk-amd64/jre/lib/amd64/server/libjvm.so)
> ==14352==    by 0xBDA5A7E: instanceKlass::call_class_initializer_impl(instanceKlassHandle, Thread*) (in /usr/lib/jvm/java-7-openjdk-amd64/jre/lib/amd64/server/libjvm.so)
> ==14352==    by 0xBDA5AF9: instanceKlass::call_class_initializer(Thread*) (in /usr/lib/jvm/java-7-openjdk-amd64/jre/lib/amd64/server/libjvm.so)
> ==14352==    by 0xBDA5CF1: instanceKlass::initialize_impl(instanceKlassHandle, Thread*) (in /usr/lib/jvm/java-7-openjdk-amd64/jre/lib/amd64/server/libjvm.so)
> ==14352==    by 0xBDA6168: instanceKlass::initialize(Thread*) (in /usr/lib/jvm/java-7-openjdk-amd64/jre/lib/amd64/server/libjvm.so)
> ==14352==    by 0xBDA5FB2: instanceKlass::initialize_impl(instanceKlassHandle, Thread*) (in /usr/lib/jvm/java-7-openjdk-amd64/jre/lib/amd64/server/libjvm.so)
> ==14352==    by 0xBDA6168: instanceKlass::initialize(Thread*) (in /usr/lib/jvm/java-7-openjdk-amd64/jre/lib/amd64/server/libjvm.so)
> ==14352==    by 0xC0BDB8D: Threads::create_vm(JavaVMInitArgs*, bool*) (in /usr/lib/jvm/java-7-openjdk-amd64/jre/lib/amd64/server/libjvm.so)
> ==14352==    by 0xBE00509: JNI_CreateJavaVM (in /usr/lib/jvm/java-7-openjdk-amd64/jre/lib/amd64/server/libjvm.so)
> ==14352==  Address 0x7feff31e0 is not stack'd, malloc'd or (recently) free'd
> 
> 
>> -pd
>> 
>> On Aug 10, 2012, at 19:51 , Zhang, Peng wrote:
>> 
>>> Thanks! It is interesting that Windows has pointed the problem to Java.
>>> So it is probable that how I did my debug led me to the wrong direction.
>>> 
>>> Since I was unsure how to debug S4 class, I copied the source implement
>>> R function from glmulti package into my testing program.
>>> 
>>> The segmentation fault will appear when I step to "neotete =
>>> terms(as.formula(paste("h~",paste(preds, collapse="*"))))". That is why
>>> I have asked my initial question on the board.
>>> 
>>> The more interesting thing is that if I don't run library(glmulti), but
>>> just the following lines, I won't have problem when I stepped to that
>>> terms function.
>>> 
>>> I am totally lost. It is not clear to me how to debug S4 class.
>>> 
>>> Best,
>>> Peng
>>> 
>>> ### beginning
>>> library(glmulti)
>>> 
>>> testdata = cbind(Y=rnorm(100), data.frame(matrix(rnorm(100*50), ncol = 50)))
>>> 
>>> glmulti =
>>> function(y, xr, data, exclude, name, intercept, marginality , bunch,
>>> chunk, chunks,
>>>         level, minsize, maxsize, minK, maxK,
>>> method,crit,confsetsize,popsize,mutrate,
>>>         sexrate,imm, plotty,  report, deltaM, deltaB, conseq,
>>> fitfunction, resumefile, includeobjects, ...) {
>>>     if (missing(data))
>>>         tete = terms(y)
>>>     else
>>>         tete = terms(y, data=data)
>>>     oo = attr(tete,"order")
>>>     dep = as.character(attr(tete,"variables"))[2]
>>>     int = attr(tete,"intercept")
>>>     preds = as.character(attr(tete,"variables"))[-(1:2)]
>>>     if (level==2 && max(oo)>1) {
>>>         # get all possible interactions
>>>         interac = attr(tete,"term.labels")[oo==2]
>>>         neotete = terms(as.formula(paste("h~",paste(preds, collapse="*"))))
>>>         neointerac= attr(neotete,"term.labels")[attr(neotete,"order")==2]
>>>         # get exclusions
>>>         for (i in interac)
>>>             neointerac=neointerac[neointerac!=i]
>>>         # same for main effects
>>>         mama = attr(tete,"term.labels")[oo==1]
>>>         exma = preds
>>>         for (j in mama)
>>>             exma = exma[exma!=j]
>>>         exma = c(exma,neointerac)
>>>     } else {
>>>         preds = attr(tete,"term.labels")[oo==1]
>>>         exma=c(1)
>>>     }
>>>     call = match.call()
>>>     call[[match("y", names(call))]] = dep
>>>     call[[length(names(call))+1]] = preds
>>>     names(call)[length(names(call))] ="xr"
>>>         call[[length(names(call))+1]] = exma
>>>     names(call)[length(names(call))] ="exclude"
>>> 
>>>     if (missing(data)) {
>>>         call[[length(names(call))+1]] = environment(y)
>>>         names(call)[length(names(call))] ="data"
>>>     }
>>>     eval(call)
>>> }
>>> 
>>> debug(glmulti)
>>> 
>>> glmulti(Y~(X1+X2+X3+X4+X5+X6+X7+X8+X9+X10+X11+X12+X13+X14+X15)*X16,
>>> xr=NULL, data = testdata, level = 2)
>>> ###end
>>> 
>>> On 08/10/2012 11:47 AM, Henric (Nilsson) Winell wrote:
>>>> On 2012-08-10 15:42, Zhang, Peng wrote:
>>>> 
>>>>> You are right. I am running Arch Linux. However, I obtained a
>>>>> segmentation directly, so didn't know where to find the bug??
>>>>> 
>>>>>> library("glmulti")
>>>>> Loading required package: rJava
>>>>>> testdata = cbind(Y=rnorm(100), data.frame(matrix(rnorm(100*50), ncol
>>>>> = 50)))
>>>>>> glmulti(Y~(X1+X2+X3+X4+X5+X6+X7+X8+X9+X10+X11+X12+X13+X14+X15)*X16,
>>>>> data= testdata, level = 2)
>>>>> Segmentation fault
>>>>> 
>>>>> Is this information "Error in .jnew("glmulti/ModelGenerator", y,
>>>>> jarray(xc), .jarray(xq),  : java.lang.ArrayIndexOutOfBoundsException:
>>>>> 15" only in Windows, or did you see it under Fedora as well?
>>>> 
>>>> Windows only.  Fedora just returned "Segmentation fault".
>>>> 
>>>> 
>>>> //Henric
>>>> 
>>>> 
>>>> 
>>>>> 
>>>>> Thank you!
>>>>> 
>>>>> Peng
>>>>> 
>>>>> BTW:
>>>>> 
>>>>> $ uname -a
>>>>> Linux Precision 3.4.7-1-ARCH #1 SMP PREEMPT Sun Jul 29 22:02:56 CEST
>>>>> 2012 x86_64 GNU/Linux
>>>>> 
>>>>>> sessionInfo()
>>>>> R version 2.15.1 (2012-06-22)
>>>>> Platform: x86_64-unknown-linux-gnu (64-bit)
>>>>> 
>>>>> locale:
>>>>>   [1] LC_CTYPE=en_US.UTF-8       LC_NUMERIC=C
>>>>>   [3] LC_TIME=en_US.UTF-8        LC_COLLATE=en_US.UTF-8
>>>>>   [5] LC_MONETARY=en_US.UTF-8    LC_MESSAGES=en_US.UTF-8
>>>>>   [7] LC_PAPER=C                 LC_NAME=C
>>>>>   [9] LC_ADDRESS=C               LC_TELEPHONE=C
>>>>> [11] LC_MEASUREMENT=en_US.UTF-8 LC_IDENTIFICATION=C
>>>>> 
>>>>> attached base packages:
>>>>> [1] stats     graphics  grDevices utils     datasets  methods base
>>>>> 
>>>>> 
>>>>> On 08/10/2012 09:25 AM, Henric (Nilsson) Winell wrote:
>>>>>> On 2012-08-10 06:10, Zhang, Peng wrote:
>>>>>> 
>>>>>>> Thanks to both for your reply.
>>>>>>> 
>>>>>>> library(glmulti)
>>>>>>> testdata = cbind(Y=rnorm(100), data.frame(matrix(rnorm(100*50), ncol
>>>>>>> = 50)))
>>>>>>> glmulti(Y~(X1+X2+X3+X4+X5+X6+X7+X8+X9+X10+X11+X12+X13+X14+X15)*X16,
>>>>>>> data
>>>>>>> = testdata, level = 2)
>>>>>>> 
>>>>>>> This is reproducible to get a segmentation fault.
>>>>>> 
>>>>>> There's some information missing here, notably the output from
>>>>>> 'sessionInfo()', but I guess this is under GNU/Linux.  I can confirm a
>>>>>> seg. fault under Fedora FC17 x86_64.
>>>>>> 
>>>>>> Under Windows 7 64-bit, however, we get some further info:
>>>>>> 
>>>>>>> library("glmulti")
>>>>>> Loading required package: rJava
>>>>>>> testdata = cbind(Y=rnorm(100), data.frame(matrix(rnorm(100*50), ncol
>>>>>> = 50)))
>>>>>>> glmulti(Y~(X1+X2+X3+X4+X5+X6+X7+X8+X9+X10+X11+X12+X13+X14+X15)*X16,
>>>>>> data
>>>>>> + = testdata, level = 2)
>>>>>> Initialization...
>>>>>> Error in .jnew("glmulti/ModelGenerator", y, .jarray(xc),
>>>>>> .jarray(xq),  :
>>>>>>   java.lang.ArrayIndexOutOfBoundsException: 15
>>>>>>> 
>>>>>>> sessionInfo()
>>>>>> R version 2.15.1 Patched (2012-08-06 r60178)
>>>>>> Platform: x86_64-w64-mingw32/x64 (64-bit)
>>>>>> 
>>>>>> locale:
>>>>>> [1] LC_COLLATE=Swedish_Sweden.1252 LC_CTYPE=Swedish_Sweden.1252
>>>>>> [3] LC_MONETARY=Swedish_Sweden.1252 LC_NUMERIC=C
>>>>>> [5] LC_TIME=Swedish_Sweden.1252
>>>>>> 
>>>>>> attached base packages:
>>>>>> [1] stats     graphics  grDevices utils     datasets  methods base
>>>>>> 
>>>>>> other attached packages:
>>>>>> [1] glmulti_1.0.4 rJava_0.9-3
>>>>>>> 
>>>>>> 
>>>>>> So, this doesn't seem to be a bug in R and is thus likely to need the
>>>>>> attention of the 'glmulti' package's maintainer.
>>>>>> 
>>>>>> 
>>>>>> HTH,
>>>>>> Henric
>>>>>> 
>>>>>> 
>>>>>> 
>>>>>>> But I have troubles to
>>>>>>> extract the exact information from this S4 class to make a simpler
>>>>>>> example because of my limited knowledge on S4 class. The author of the
>>>>>>> package is busy at the moment, and does not have time to look into it.
>>>>>>> 
>>>>>>> Peng
>>>>>>> 
>>>>>>> On 08/09/2012 10:25 PM, R. Michael Weylandt
>>>>>>> <michael.weylandt at gmail.com>
>>>>>>> wrote:
>>>>>>>> 
>>>>>>>> On Aug 9, 2012, at 9:14 PM, David Winsemius <dwinsemius at comcast.net>
>>>>>>>> wrote:
>>>>>>>> 
>>>>>>>>> On Aug 9, 2012, at 4:56 PM, Zhang, Peng wrote:
>>>>>>>>> 
>>>>>>>>>> Dear all,
>>>>>>>>>> 
>>>>>>>>>> I had a R segmentation fault, and then invoked debug mode and ran
>>>>>>>>>> step
>>>>>>>>>> by step.
>>>>>>>>> 
>>>>>>>>>> 2. Why does the same function behave differently under debug and
>>>>>>>>>> regular
>>>>>>>>>> mode?
>>>>>>>>> I cannot help you there.
>>>>>>>>> 
>>>>>>>> Though a reproducible segfault is certainly worth a bug report if
>>>>>>>> you can do so, in debug or regular modes.
>>>>>>>> 
>>>>>>>> You may wish to search stackoverflow for tips on how to make a great
>>>>>>>> reproducible example in R.
>>>>>>>> 
>>>>>>>> Michael
>>>>>>> **********************************************************
>>>>>>> Electronic Mail is not secure, may not be read every day, and should
>>>>>>> not be used for urgent or sensitive issues
>>>>>>> 
>>>>>>> ______________________________________________
>>>>>>> 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.
>>>>>>> 
>>>>>> 
>>>>> **********************************************************
>>>>> Electronic Mail is not secure, may not be read every day, and should
>>>>> not be used for urgent or sensitive issues
>>>>> 
>>>>> 
>>>> 
>>> **********************************************************
>>> Electronic Mail is not secure, may not be read every day, and should not be used for urgent or sensitive issues
>>> 
>>> ______________________________________________
>>> 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.
>> 
> 
> 
> -- 
> Computational Biology / Fred Hutchinson Cancer Research Center
> 1100 Fairview Ave. N.
> PO Box 19024 Seattle, WA 98109
> 
> Location: Arnold Building M1 B861
> Phone: (206) 667-2793
> 
> 



[Rd] [R] debug vs regular mode
Simon Urbanek