gmane.comp.shells.zsh.user

Rocky Bernstein | 28 Sep 21:16

Help me track down a tough bug? (probably funcfiletrace, subshells and possibly I/O redirection)

There is what looks to me a bug in the recent funcfiletrace that I've
been trying to isolate. I've spent the weekend on this and have made
some progress but have to stop now. Perhaps there's someone out there
who can help further pinpoint this bug.

You'll need the most recent zsh in CVS. If you have zshdb installed
(and chances are you don't) you can see the bug by
running this program under the debugger

#!/usr/local/bin/zsh
# Test debugger handling of subshells
(
    x=$(print 5; print 6)
)

Below I'll show output from a sample session using the debugger. I've
put comments to the side (in #) to try to explain what's going on.

$ zshdb -q /tmp/zshdb/testing.sh   # run testing.sh
(/tmp/zshdb/testing.sh:3):         # file and line number
( x=$(print 5; print 6) )          # What's going to get run next
zshdb<4> s                         # 's' issues a "step" command

(/tmp/zshdb/testing.sh:4):
x=$(print 5; print 6)              # Note we are in a subshell
zshdb<(5)> s                       # the () indicates this

(/tmp/zshdb/testing.sh:1):
print 5                            # In a 2nd subshell, backtick
zshdb<((7))> where                 # ((..)) indicates this.

(Continue reading)

Peter Stephenson | 28 Sep 23:16

Re: Help me track down a tough bug? (probably funcfiletrace, subshells and possibly I/O redirection)

On Sun, 28 Sep 2008 15:19:37 -0400
"Rocky Bernstein" <rocky.bernstein <at> gmail.com> wrote:
> There is what looks to me a bug in the recent funcfiletrace that I've
> been trying to isolate.
> 
> #!/usr/local/bin/zsh
> # Test debugger handling of subshells
> (
>     x=$(print 5; print 6)
> )
> (/tmp/zshdb/testing.sh:1):
> print 5                            # In a 2nd subshell, backtick
> zshdb<((7))> where                 # ((..)) indicates this.
>
> What's wrong is that we aren't on line 1 of testing.sh.

exec.c:parse_string() resets the line number for every invocation.
That's fine for eval, where we've fixed this up explicitly, but doesn't
work in the call from exec.c:getoutput() which is the case here.
Obviously that's not consistent with the fact that it doesn't have its
own file; we don't do the special eval handling of reconstructing the
file location in this case.

The reason (...) is different is it's parsed straight away when the
shell reads it in; it's not stored as a string argument to be looked at
again later.

It's possible we can simply get away with not resetting the line number
in any case without its own entry on the function stack.  That's about
the simplest fix, but changes the meaning of line numbers in all string

(Continue reading)

Rocky Bernstein | 29 Sep 04:32

Re: Help me track down a tough bug? (probably funcfiletrace, subshells and possibly I/O redirection)

In general I think this will help. Not just because it helps the
debugger. Later (* * * * below) I'll elaborate on this.

But in short, either this patch doesn't solve this particular problem
or I hand-applied the patch incorrectly.

(A cut and paste to a file caused many rejections by "patch", so I did
the rest by hand. It's possible I missed something. Running the
regression test caused a failures in E01options.ztst with an eval and
$LINENO, and another in C05debug.ztst with debug-trap-bug, but I think
this is to be expected. )

When I run zsh with those patches on this program:
(
    x=$(print $LINENO); print $x
)

I still get 1. Is that what one gets with the patch applied?

Note that there are other problems encountered that not explained by
that patch. In particular, it doesn't explain the position zshdb2.sh:6
in the output that went:

./command/eval.sh:4 ./command/eval.sh:22 ./lib/processor.sh:67
./lib/processor.sh:16 ./zshdb2.sh:6 ./testing.sh:1 ./zshdb2.sh:34

The correct position there is ./zshdb2.sh:9 which does appear earlier.
Also it doesn't explain the missing funcfiletrace output which could
be explained if somehow if zsh didn't think there were any function
calls.

(Continue reading)

Peter Stephenson | 29 Sep 10:52

Re: Help me track down a tough bug? (probably funcfiletrace, subshells and possibly I/O redirection)

On Sun, 28 Sep 2008 22:32:19 -0400
"Rocky Bernstein" <rocky.bernstein <at> gmail.com> wrote:
> In general I think this will help. Not just because it helps the
> debugger. Later (* * * * below) I'll elaborate on this.
> 
> But in short, either this patch doesn't solve this particular problem
> or I hand-applied the patch incorrectly.
>...
> When I run zsh with those patches on this program:
> (
>     x=$(print $LINENO); print $x
> )
> 
> I still get 1. Is that what one gets with the patch applied?

No, you should get the line number in the file as I do, and you shouldn't
get any additional test failures.  I don't think your version is working.

I've now committed it, but with one additional change:  parse_string()
still has the key additional reset_lineno logic, but it once again always
saves and restores the line number locally.  That wouldn't make a
difference in this particular case but sometimes with the previous version
(I haven't bothered tracking down the exact places) you might get the
global line number being incremented too much.  I don't think there's any
case where parsing the string should affect the line number from the
surrounding context.

> Let me see if I understand the situation correctly: there is an
> internal routine called parse_string() which can be called though eval
> as well as backtick. For eval, one can argue its the right thing, but

(Continue reading)

Rocky Bernstein | 29 Sep 13:11

Re: Help me track down a tough bug? (probably funcfiletrace, subshells and possibly I/O redirection)

Thanks. This addresses one of the problem seen. There are still the
others -- output disappearing and weird line numbers shown further up
in the trace. But we will take these one at a time.

How do you feel about noting the subshell level in one of the
traceback stacks and allowing an optional parameter to set $LINENO in
those cases where it is reset to 1. (Is there a corresponding variable
for the filename?

I note that in
x="
$LINENO"

LINENO has the x's line number rather than the one it's on. No doubt
this is an artifact of xtrace wanting to show for tracing purposes x's
line. However probably more correct would be to keep that but have
$LINENO be the line that it itself is on.

However assuming this is what's desired,  attached is a test for the
recent lineno-in-subshell change as well as a test for the LINENO in
split assignment. Adjust that last test as desired.

I've put these in a separate file and my test would be to move some of
the other LINENO tests out of the overall variable test here, use
again adjust (or discard) as desired.

On Mon, Sep 29, 2008 at 4:52 AM, Peter Stephenson <pws <at> csr.com> wrote:
> On Sun, 28 Sep 2008 22:32:19 -0400
> "Rocky Bernstein" <rocky.bernstein <at> gmail.com> wrote:
>> In general I think this will help. Not just because it helps the

(Continue reading)

Peter Stephenson | 29 Sep 13:25

Re: Help me track down a tough bug? (probably funcfiletrace, subshells and possibly I/O redirection)

"Rocky Bernstein" wrote:
> Thanks. This addresses one of the problem seen. There are still the
> others -- output disappearing and weird line numbers shown further up
> in the trace. But we will take these one at a time.

Please could you send a simple example of a remaining incorrect line
number.  I would expect it would be reproducible without the debugger.

> How do you feel about noting the subshell level in one of the
> traceback stacks and allowing an optional parameter to set $LINENO in
> those cases where it is reset to 1.

I'm not entirely sure what you're referring to, please could you give an
example of what behaviour you'd like.

> (Is there a corresponding variable for the filename?

LINENO itself doesn't necessarily relate to a file, but for now you can
use ${(%):-%x} and ${(%):-%I} for the filename and line number in the
shell code which is probably what you need.  I'll add variables for
these later if they turn out to be useful (probably ZSH_SOURCE_FILE and
ZSH_SOURCE_LINE).

> I note that in
> x="
> $LINENO"
> 
> LINENO has the x's line number rather than the one it's on. No doubt
> this is an artifact of xtrace wanting to show for tracing purposes x's
> line. However probably more correct would be to keep that but have

(Continue reading)

Rocky Bernstein | 29 Sep 16:11

Re: Help me track down a tough bug? (probably funcfiletrace, subshells and possibly I/O redirection)

On Mon, Sep 29, 2008 at 7:25 AM, Peter Stephenson <pws <at> csr.com> wrote:
> "Rocky Bernstein" wrote:
>> Thanks. This addresses one of the problem seen. There are still the
>> others -- output disappearing and weird line numbers shown further up
>> in the trace. But we will take these one at a time.
>
> Please could you send a simple example of a remaining incorrect line
> number.  I would expect it would be reproducible without the debugger.

Sorry. Here's a trace from the reduced debugger. I've added comments as before.

./zshdb2.sh
./zshdb2.sh:39 ./zshdb2.sh:34   # Debug output in lib/frame.sh

# Above should be: ./lib/hook.sh:5 ./zshdb2.sh:34
# note: 34+5=39

(./zshdb2.sh:34):               # Comes from debugger via above save
. ./testing.sh
./zshdb2.sh:39 ./zshdb2.sh:34   # lib/frame.sh output again
zshdb<1> p ${funcfiletrace[@]}
./command/eval.sh:38 ./command/eval.sh:56 ./lib/processor.sh:100
./lib/processor.sh:49 ./zshdb2.sh:39 ./zshdb2.sh:34

# Above should be:  ./command/eval.sh:11 ./command/eval.sh:27
./lib/processor.sh:96 ./lib/processor.sh:44 ./lib/hook:13
./lib/hook.sh:6 ./zshdb2.sh:39 ./zshdb2.sh:34

Note that the difference in the two ./lib/processor.sh call lines is
52 in one case and 51 in another.

(Continue reading)

Peter Stephenson | 29 Sep 16:25

Re: Help me track down a tough bug? (probably funcfiletrace, subshells and possibly I/O redirection)

"Rocky Bernstein" wrote:
> ./zshdb2.sh
> ./zshdb2.sh:39 ./zshdb2.sh:34   # Debug output in lib/frame.sh
> 
> # Above should be: ./lib/hook.sh:5 ./zshdb2.sh:34
> # note: 34+5=39

Ah, I see, so this should be fairly obvious once I track back and see
what the code referred to is... I'll try and get round to this this
evening.

> Suppose eval line numbers were reset but it is shown as a call in the
> stack traces as it is in Python and Ruby. This code then
> 
> # This is line 5
> eval "x=1;
> y=$LINENO"
> 
> would set y to 2 since that's the second line in the eval. Since eval
> is a POSIX "special" builtin, let's say there is an eval2 which allows
> optional file and line number parameters
> 
> eval "x=1;
> y=$LINENO" 10 foo.c
> 
> Then y would be set to 10. And *stack* routines where we can see
> filename, it would be "foo.c"

There is already an EVALLINENO option to control the line number
behaviour in eval.  I wouldn't plan on making this even more complicated

(Continue reading)

Peter Stephenson | 29 Sep 23:42

Re: Help me track down a tough bug? (probably funcfiletrace, subshells and possibly I/O redirection)

On Mon, 29 Sep 2008 15:25:28 +0100
Peter Stephenson <pws <at> csr.com> wrote:
> "Rocky Bernstein" wrote:
> > ./zshdb2.sh
> > ./zshdb2.sh:39 ./zshdb2.sh:34   # Debug output in lib/frame.sh
> > 
> > # Above should be: ./lib/hook.sh:5 ./zshdb2.sh:34
> > # note: 34+5=39
> 
> Ah, I see, so this should be fairly obvious once I track back and see
> what the code referred to is... I'll try and get round to this this
> evening.

Wasn't so easy, since there was quite a lot of irrelevant stuff to
strip.  It turns out the problem is handling of functions inside traps.
These inherit the behaviour of the parent (eval-style, i.e. not
TRAP...() { ... } ) trap that the line number isn't updated, it's kept
as that in the line that caused the trap.  This causes oddities like
this, so I think it wants turning off so that the functions called from
the trap act normally.  This seems to accord with the principle of least
surprise, too.  That seems to fix the problem, but I'm sure I'll be
hearing if it doesn't.  I suspect sources inside eval-style traps behave
similarly and ought to be fixed, which could be done with sourcelevel,
but sufficient unto the day etc.  (The tests could also be done by
pushing a special FS_TRAP type onto funcstack, but that has obvious
visible consequences.  funcstack is a relative latecomer and could have
been used for also sorts of things we now do other ways.)

Responses avoiding "it should have been done completely differently from
the start", "it would be nice to have an option to do it completely

(Continue reading)

Rocky Bernstein | 30 Sep 02:18

Re: Help me track down a tough bug? (probably funcfiletrace, subshells and possibly I/O redirection)

On Mon, Sep 29, 2008 at 5:42 PM, Peter Stephenson
<p.w.stephenson <at> ntlworld.com> wrote:
> On Mon, 29 Sep 2008 15:25:28 +0100
> Peter Stephenson <pws <at> csr.com> wrote:
>> "Rocky Bernstein" wrote:
>> > ./zshdb2.sh
>> > ./zshdb2.sh:39 ./zshdb2.sh:34   # Debug output in lib/frame.sh
>> >
>> > # Above should be: ./lib/hook.sh:5 ./zshdb2.sh:34
>> > # note: 34+5=39
>>
>> Ah, I see, so this should be fairly obvious once I track back and see
>> what the code referred to is... I'll try and get round to this this
>> evening.
>
> Wasn't so easy, since there was quite a lot of irrelevant stuff to
> strip.

If you started with zshdb-0.01bug, if it is of any consolation, I'd
been stripping stuff out all weekend, well as trying to create simple
test cases. If you started with the git source well, yes, that's quite
large.

>  It turns out the problem is handling of functions inside traps.
> These inherit the behaviour of the parent (eval-style, i.e. not
> TRAP...() { ... } ) trap that the line number isn't updated, it's kept
> as that in the line that caused the trap.  This causes oddities like
> this, so I think it wants turning off so that the functions called from
> the trap act normally.  This seems to accord with the principle of least
> surprise, too.

(Continue reading)

Peter Stephenson | 30 Sep 18:53

Re: Help me track down a tough bug? (probably funcfiletrace, subshells and possibly I/O redirection)

On Mon, 29 Sep 2008 20:18:52 -0400
"Rocky Bernstein" <rocky.bernstein <at> gmail.com> wrote:
> zshdb<3> p ${funcfiletrace[@]}
> 
> ./command/eval.sh:11 ./command/eval.sh:27 ./lib/processor.sh:96
> ./lib/processor.sh:44 ./zshdb2.sh:9 ./testing.sh:3 ./zshdb2.sh:34
> ./command/eval.sh:11 ./command/eval.sh:27 ./lib/processor.sh:96
> ./lib/processor.sh:44 ./zshdb2.sh:9 ./testing.sh:3 ./zshdb2.sh:34
> ./zshdb2.sh:9 ./testing.sh:3 ./zshdb2.sh:34
> # Were did that double set of lines come from?

Hmmm... I'm not convinced this has got anything directly to do with the
shell rather than the debugger.  Here's what I get when I simply ask for
the PID repeated times:

---------------
./zshdb2.sh:7 ./zshdb2.sh:34
===============
(./zshdb2.sh:34):
. ./testing.sh
./zshdb2.sh:9 ./zshdb2.sh:34
zshdb<1> p $$
711
./zshdb2.sh:9 ./zshdb2.sh:34
zshdb<2> p $$
711
711
./zshdb2.sh:9 ./zshdb2.sh:34
zshdb<3> p $$
711

(Continue reading)

Rocky Bernstein | 30 Sep 19:59

Re: Help me track down a tough bug? (probably funcfiletrace, subshells and possibly I/O redirection)

My mistake. You are correct. This bug was introduced in paring down
the program and removing an initial truncate output (leaving the
subsequent append outputs). And I now see the answer to why output was
disappearing in the subshell which was my initial concern.

Thanks for all the help!

Any thoughts on marking subshell level inside one of the stack traces
or having return inside trap DEBUG with a negative number cause an
immediate return?

Thanks again.

On Tue, Sep 30, 2008 at 12:53 PM, Peter Stephenson <pws <at> csr.com> wrote:
> On Mon, 29 Sep 2008 20:18:52 -0400
> "Rocky Bernstein" <rocky.bernstein <at> gmail.com> wrote:
>> zshdb<3> p ${funcfiletrace[@]}
>>
>> ./command/eval.sh:11 ./command/eval.sh:27 ./lib/processor.sh:96
>> ./lib/processor.sh:44 ./zshdb2.sh:9 ./testing.sh:3 ./zshdb2.sh:34
>> ./command/eval.sh:11 ./command/eval.sh:27 ./lib/processor.sh:96
>> ./lib/processor.sh:44 ./zshdb2.sh:9 ./testing.sh:3 ./zshdb2.sh:34
>> ./zshdb2.sh:9 ./testing.sh:3 ./zshdb2.sh:34
>> # Were did that double set of lines come from?
>
> Hmmm... I'm not convinced this has got anything directly to do with the
> shell rather than the debugger.  Here's what I get when I simply ask for
> the PID repeated times:
>
> ---------------

(Continue reading)

Rocky Bernstein | 30 Sep 20:01

Re: Help me track down a tough bug? (probably funcfiletrace, subshells and possibly I/O redirection)

In that last email it looks like stuff I had written before figuring
out what was wrong was inadvertently keep in the email. I mean to send
just the initial text, not the inline comments.

Peter Stephenson | 1 Oct 13:31

Re: Help me track down a tough bug? (probably funcfiletrace, subshells and possibly I/O redirection)

On Tue, 30 Sep 2008 13:59:43 -0400
"Rocky Bernstein" <rocky.bernstein <at> gmail.com> wrote:
> My mistake. You are correct. This bug was introduced in paring down
> the program and removing an initial truncate output (leaving the
> subsequent append outputs). And I now see the answer to why output was
> disappearing in the subshell which was my initial concern.

OK, so it seems there's currently nothing for me to look at here.

> Any thoughts on marking subshell level inside one of the stack traces
> or having return inside trap DEBUG with a negative number cause an
> immediate return?

You can already force a return from the enclosing function from trap '...'
DEBUG just by executing "return".  You can use return from within enclosing
functions to trigger this, e.g.

  fn() {
    return 3
  }
  trap 'fn || return $?' DEBUG

(if you need to return status 0, offset the status return value from fn by
1 and use 'fn || return $(( $? - 1 ))').  For example

  foo() {
    emulate -L zsh
    trap '[[ $ZSH_DEBUG_CMD == *bar* ]] && return 1' DEBUG
    echo foo
    echo bar

(Continue reading)

Rocky Bernstein | 1 Oct 17:45

Re: Help me track down a tough bug? (probably funcfiletrace, subshells and possibly I/O redirection)

On Wed, Oct 1, 2008 at 7:31 AM, Peter Stephenson <pws <at> csr.com> wrote:
> On Tue, 30 Sep 2008 13:59:43 -0400
> "Rocky Bernstein" <rocky.bernstein <at> gmail.com> wrote:
>> My mistake. You are correct. This bug was introduced in paring down
>> the program and removing an initial truncate output (leaving the
>> subsequent append outputs). And I now see the answer to why output was
>> disappearing in the subshell which was my initial concern.
>
> OK, so it seems there's currently nothing for me to look at here.

Yep. Thanks for the help though.

>
>> Any thoughts on marking subshell level inside one of the stack traces
>> or having return inside trap DEBUG with a negative number cause an
>> immediate return?
>
> You can already force a return from the enclosing function from trap '...'
> DEBUG just by executing "return".  ...

Ok. I've just committed a gdb-style "return" statement then.

Thoughts about being able to see subshell nexting inside the various
traces? (The level number really isn't needed, just a bit to indicate
whether a new subshell was entered.)

Thanks.

Return

Return to gmane.comp.shells.zsh.user.

Advertisement

Search Archive

Language

Change language

Options

Current view: Threads only / Showing only 20 lines / Not hiding cited text.
Change to All messages, whole messages, or hide cited text.

Post a message
NNTP Newsgroup
Classic Gmane web interface
XML

XML

RSS Feed
List Information

About Gmane