R devel - Dec 2016 - why does parent.frame() cycle when called from inside capture.output()?

Hello R devel/help,

I ran into this strange behavior:

    # showstack is supposed to walk through the stack of parent
    # environments when it is called:
    showstack = function() {
      env = environment()
      for(i in 1:12) {
        env = do.call(parent.frame, list(), env=env)
        print(env)
      }
    }

    # a simple chain of functions:
    g3=function(t) showstack()
    g2=function(w) g3(w)
    g1=function(z) g2(z)
    g=function(y) g1(y)

    g()
    # outputs:
    # <environment: 0xb5ef810>
    # <environment: 0xb5ef6f8>
    # <environment: 0xb5ef5e0>
    # <environment: 0xb5ef4c8>
    # <environment: R_GlobalEnv>
    # <environment: R_GlobalEnv>
    # <environment: R_GlobalEnv>
    # <environment: R_GlobalEnv>
    # <environment: R_GlobalEnv>
    # ...

    cat(capture.output(g()),sep="\n")
    # outputs:
    # <environment: 0x8106a30>
    # <environment: 0x8106918>
    # <environment: 0x8106800>
    # <environment: 0x81066e8>
    # <environment: R_GlobalEnv>
    # <environment: 0x8107458>
    # <environment: 0x81071b8>
    # <environment: 0x80c6a08>
    # <environment: R_GlobalEnv>
    # <environment: 0x8107458>
    # <environment: 0x81071b8>
    # <environment: 0x80c6a08>

The strange thing of course is that the second call doesn't stay with
R_GlobalEnv, but in fact goes into a loop of period 4. I'm not so
surprised that the parent frame of the global environment is itself,
as in the first call, but it seems weird to have a loop of period 4...
Using `ls()` shows that two of the "loop" environments belong to
capture.output() and eval().

But if capture.output is really evaluating its input in the parent
frame, as it appears to be doing from its source code, then I would
have expected the output to be the same as the output I get by
evaluating the same expression in this frame.

I was trying to debug a function which attempts to be a multi-frame
version of deparse(substitute(...)). I'm attaching this function in
case anyone is curious. Perhaps my attachment can shed more light on
the problem I'm having.

Apologies if this is not a bug - I wasn't sure which mailing list to
send this to, and I took a guess.

Thanks,

Frederick
-------------- next part --------------
desubN <- function(y,n=1) {
  env=environment();
  for(i in 1:n) {
    y = do.call(substitute, list(substitute(y)), env=env)
    env = do.call(parent.frame, list(), env=env)
  }
  deparse(y)
}
g2=function(t) {
  for(i in 1:5) {
    print(desubN(t,i))
    print(capture.output(desubN(t,i)))
  }
}
g1=function(z) g2(z)
g=function(y) g1(y)

g(log)
# output: (why does it stop at "z"?)
## [1] "t"
## [1] "[1] \"t\""
## [1] "z"
## [1] "[1] \"z\""
## [1] "y"
## [1] "[1] \"z\""
## [1] "log"
## [1] "[1] \"z\""
## [1] "log"
## [1] "[1] \"z\""

Thanks, Mark - I'm taking up your invitation to forward your message
to the list just because it gives us some valuable data on (1) how
long the behavior has been around, and (2) how many other people
(don't) understand the behavior, and (3) how we might fix or work
around it.

I notice some other people also seem to be diffident about posting on
R-devel; perhaps I should conclude that bugs like this are below the
radar for busy statisticians.

FWIW, after playing around a bit with mvbutils::mvb.parent.frame, I
now have a working "desubN" (see the attachment on my original
message, and this one). I don't really have a good understanding of
*why* it now works, and why the original version didn't work...

Thanks again Mark. Also, nice hacking.

Frederick

----- Forwarded message from Mark.Bravington at data61.csiro.au -----

Date: Mon, 12 Dec 2016 06:20:17 +0000
From: Mark.Bravington at data61.csiro.au
To: frederik at ofb.net
Subject: RE: [Rd] why does parent.frame() cycle when called from inside
	capture.output()?
X-Spam-Status: No, score=-2.0 required=5.0 tests=BAYES_00,DKIM_SIGNED,
	DKIM_VALID,DKIM_VALID_AU,T_SPF_HELO_TEMPERROR,T_SPF_TEMPERROR autolearn=ham
	autolearn_force=no version=3.4.1
X-Spam-Level: 
X-My-Tags: inbox r-devel

Hi Frederik

[ I'm replying off-list in case you, or the rest of R-devel, don't find
this reply useful... please fwd to the list if it does help you ]

I'm the author of the 'debug' package. When I wrote it--- many years
ago now--- I encountered some fairly strange behaviour with frames in the call
stack, which is reminiscent of what you're seeing. The debug package still
works fine, so I presume nothing has changed much.

If you load debug and then do ?mvb.sys.parent (and look at the code), you might
get *some* idea of what's going on. TBH I can't remember the details
now...

HTH
Mark

Mark Bravington
CSIRO Marine Lab
Hobart
Australia

________________________________________
From: R-devel [r-devel-bounces at r-project.org] on behalf of frederik at
ofb.net [frederik at ofb.net]
Sent: 12 December 2016 16:54
To: r-devel at r-project.org
Cc: r-help at r-project.org
Subject: [Rd] why does parent.frame() cycle when called from inside
capture.output()?

Hello R devel/help,

I ran into this strange behavior:

    # showstack is supposed to walk through the stack of parent
    # environments when it is called:
    showstack = function() {
      env = environment()
      for(i in 1:12) {
        env = do.call(parent.frame, list(), env=env)
        print(env)
      }
    }

    # a simple chain of functions:
    g3=function(t) showstack()
    g2=function(w) g3(w)
    g1=function(z) g2(z)
    g=function(y) g1(y)

    g()
    # outputs:
    # <environment: 0xb5ef810>
    # <environment: 0xb5ef6f8>
    # <environment: 0xb5ef5e0>
    # <environment: 0xb5ef4c8>
    # <environment: R_GlobalEnv>
    # <environment: R_GlobalEnv>
    # <environment: R_GlobalEnv>
    # <environment: R_GlobalEnv>
    # <environment: R_GlobalEnv>
    # ...

    cat(capture.output(g()),sep="\n")
    # outputs:
    # <environment: 0x8106a30>
    # <environment: 0x8106918>
    # <environment: 0x8106800>
    # <environment: 0x81066e8>
    # <environment: R_GlobalEnv>
    # <environment: 0x8107458>
    # <environment: 0x81071b8>
    # <environment: 0x80c6a08>
    # <environment: R_GlobalEnv>
    # <environment: 0x8107458>
    # <environment: 0x81071b8>
    # <environment: 0x80c6a08>

The strange thing of course is that the second call doesn't stay with
R_GlobalEnv, but in fact goes into a loop of period 4. I'm not so
surprised that the parent frame of the global environment is itself,
as in the first call, but it seems weird to have a loop of period 4...
Using `ls()` shows that two of the "loop" environments belong to
capture.output() and eval().

But if capture.output is really evaluating its input in the parent
frame, as it appears to be doing from its source code, then I would
have expected the output to be the same as the output I get by
evaluating the same expression in this frame.

I was trying to debug a function which attempts to be a multi-frame
version of deparse(substitute(...)). I'm attaching this function in
case anyone is curious. Perhaps my attachment can shed more light on
the problem I'm having.

Apologies if this is not a bug - I wasn't sure which mailing list to
send this to, and I took a guess.

Thanks,

Frederick


----- End forwarded message -----
-------------- next part --------------
# We can't just use `mvb.parent.frame` as a replacement for
# `parent.frame`, because the former throws an error when there is no
# parent frame - while we had relied on the latter gracefully giving
# us the global environment. So here's a wrapper which gives
# mvb.parent.frame the behavior we want:

my_mvb_parent=function() {
  tryCatch(
    mvb.parent.frame(2),
    error=function(e) { globalenv()})
}

desubN <- function(y,n=1) {
  env=environment();
  for(i in 1:n) {
    y = do.call(substitute, list(substitute(y)), env=env)
    env = do.call(my_mvb_parent, list(), env=env)
  }
  deparse(y)
}
g2=function(t) {
  for(i in 1:5) {
    print(desubN(t,i))
    print(capture.output(desubN(t,i)))
  }
}
g1=function(z) g2(z)
g=function(y) g1(y)

g(log)

# now capture.output seems to give the same results as the bare
# expression
## [1] "t"
## [1] "[1] \"t\""
## [1] "z"
## [1] "[1] \"z\""
## [1] "y"
## [1] "[1] \"y\""
## [1] "log"
## [1] "[1] \"log\""
## [1] "log"
## [1] "[1] \"log\""

Hi Frederik

Goodo, glad you found mvbutils::mvb.parent.frame useful. I had forgotten that
it's in mvbutils rather than debug package. This all dates back about 15
years...

To be fair, I don't think R's behaviour with duplicated-but-aliased
frames in the call stack is a "bug"--- everything normal just works---
and it's not something to be "fixed" IMO, since it's clearly
built-in by design and who knows what else would break if it got changed? But,
working round it is indeed sometimes necessary...

[ BTW I'm not particularly diffident about posting to R-devel--- eg here I
am!--- but I'm generally too busy to check out my own answers thoroughly, so
rather than risk opening up blind alleys, I tend to suggest things off-list. In
the cases where I'm sure that I do have a good answer, someone else has
already usually responded... ]

bye
mark

Mark Bravington
CSIRO Marine Lab
Hobart
Australia

________________________________________
From: frederik at ofb.net [frederik at ofb.net]
Sent: 12 December 2016 19:23
To: R-devel at r-project.org
Cc: Bravington, Mark (Data61, Hobart); r-help at r-project.org
Subject: [RE: [Rd] why does parent.frame() cycle when called from inside
capture.output()?]

Thanks, Mark - I'm taking up your invitation to forward your message
to the list just because it gives us some valuable data on (1) how
long the behavior has been around, and (2) how many other people
(don't) understand the behavior, and (3) how we might fix or work
around it.

I notice some other people also seem to be diffident about posting on
R-devel; perhaps I should conclude that bugs like this are below the
radar for busy statisticians.

FWIW, after playing around a bit with mvbutils::mvb.parent.frame, I
now have a working "desubN" (see the attachment on my original
message, and this one). I don't really have a good understanding of
*why* it now works, and why the original version didn't work...

Thanks again Mark. Also, nice hacking.

Frederick

----- Forwarded message from Mark.Bravington at data61.csiro.au -----

Date: Mon, 12 Dec 2016 06:20:17 +0000
From: Mark.Bravington at data61.csiro.au
To: frederik at ofb.net
Subject: RE: [Rd] why does parent.frame() cycle when called from inside
        capture.output()?
X-Spam-Status: No, score=-2.0 required=5.0 tests=BAYES_00,DKIM_SIGNED,
        DKIM_VALID,DKIM_VALID_AU,T_SPF_HELO_TEMPERROR,T_SPF_TEMPERROR
autolearn=ham
        autolearn_force=no version=3.4.1
X-Spam-Level:
X-My-Tags: inbox r-devel

Hi Frederik

[ I'm replying off-list in case you, or the rest of R-devel, don't find
this reply useful... please fwd to the list if it does help you ]

I'm the author of the 'debug' package. When I wrote it--- many years
ago now--- I encountered some fairly strange behaviour with frames in the call
stack, which is reminiscent of what you're seeing. The debug package still
works fine, so I presume nothing has changed much.

If you load debug and then do ?mvb.sys.parent (and look at the code), you might
get *some* idea of what's going on. TBH I can't remember the details
now...

HTH
Mark

Mark Bravington
CSIRO Marine Lab
Hobart
Australia

________________________________________
From: R-devel [r-devel-bounces at r-project.org] on behalf of frederik at
ofb.net [frederik at ofb.net]
Sent: 12 December 2016 16:54
To: r-devel at r-project.org
Cc: r-help at r-project.org
Subject: [Rd] why does parent.frame() cycle when called from inside
capture.output()?

Hello R devel/help,

I ran into this strange behavior:

    # showstack is supposed to walk through the stack of parent
    # environments when it is called:
    showstack = function() {
      env = environment()
      for(i in 1:12) {
        env = do.call(parent.frame, list(), env=env)
        print(env)
      }
    }

    # a simple chain of functions:
    g3=function(t) showstack()
    g2=function(w) g3(w)
    g1=function(z) g2(z)
    g=function(y) g1(y)

    g()
    # outputs:
    # <environment: 0xb5ef810>
    # <environment: 0xb5ef6f8>
    # <environment: 0xb5ef5e0>
    # <environment: 0xb5ef4c8>
    # <environment: R_GlobalEnv>
    # <environment: R_GlobalEnv>
    # <environment: R_GlobalEnv>
    # <environment: R_GlobalEnv>
    # <environment: R_GlobalEnv>
    # ...

    cat(capture.output(g()),sep="\n")
    # outputs:
    # <environment: 0x8106a30>
    # <environment: 0x8106918>
    # <environment: 0x8106800>
    # <environment: 0x81066e8>
    # <environment: R_GlobalEnv>
    # <environment: 0x8107458>
    # <environment: 0x81071b8>
    # <environment: 0x80c6a08>
    # <environment: R_GlobalEnv>
    # <environment: 0x8107458>
    # <environment: 0x81071b8>
    # <environment: 0x80c6a08>

The strange thing of course is that the second call doesn't stay with
R_GlobalEnv, but in fact goes into a loop of period 4. I'm not so
surprised that the parent frame of the global environment is itself,
as in the first call, but it seems weird to have a loop of period 4...
Using `ls()` shows that two of the "loop" environments belong to
capture.output() and eval().

But if capture.output is really evaluating its input in the parent
frame, as it appears to be doing from its source code, then I would
have expected the output to be the same as the output I get by
evaluating the same expression in this frame.

I was trying to debug a function which attempts to be a multi-frame
version of deparse(substitute(...)). I'm attaching this function in
case anyone is curious. Perhaps my attachment can shed more light on
the problem I'm having.

Apologies if this is not a bug - I wasn't sure which mailing list to
send this to, and I took a guess.

Thanks,

Frederick


----- End forwarded message -----