Bug 13313

Summary: Can't parse SDT_V3 operand '(%rcx,%rax,8)'
Product: systemtap Reporter: Josh Stone <jistone>
Component: tapsetsAssignee: Unassigned <systemtap>
Status: RESOLVED FIXED    
Severity: normal CC: fche, mark, sergiodj
Priority: P2    
Version: unspecified   
Target Milestone: ---   
Host: Target:
Build: Last reconfirmed:

Description Josh Stone 2011-10-18 05:33:54 UTC
It seems there's yet another new SDT operand in town, with systemtap.git compiled by gcc-4.6.1-10.fc16.x86_64.

$ stap -e 'probe process("stap").mark("cache__clean") { println($arg1) }'
WARNING: Can't parse SDT_V3 operand '(%rcx,%rax,8)': identifier '$arg1' at <input>:1:54
 source: probe process("stap").mark("cache__clean") { println($arg1) }
                                                              ^
semantic error: unable to find local 'arg1' near pc 0x4f6320  in  <unknown> ../cache.cxx ( (alternatives: $j): identifier '$arg1' at :1:54
        source: probe process("stap").mark("cache__clean") { println($arg1) }
                                                                     ^
Pass 2: analysis failed.  Try again with another '--vp 01' option.


$ objdump -s -j .note.stapsdt stap-cache.o

stap-cache.o:     file format elf64-x86-64

Contents of section .note.stapsdt:
 0000 08000000 3b000000 03000000 73746170  ....;.......stap
 0010 73647400 00000000 00000000 00000000  sdt.............
 0020 00000000 00000000 00000000 73746170  ............stap
 0030 00636163 68655f5f 67657400 38402572  .cache__get.8@%r
 0040 64782038 40363838 28257262 70290000  dx 8@688(%rbp)..
 0050 08000000 3a000000 03000000 73746170  ....:.......stap
 0060 73647400 00000000 00000000 00000000  sdt.............
 0070 00000000 00000000 00000000 73746170  ............stap
 0080 00636163 68655f5f 636c6561 6e003840  .cache__clean.8@
 0090 28257263 782c2572 61782c38 29000000  (%rcx,%rax,8)...
 00a0 08000000 47000000 03000000 73746170  ....G.......stap
 00b0 73647400 00000000 00000000 00000000  sdt.............
 00c0 00000000 00000000 00000000 73746170  ............stap
 00d0 00636163 68655f5f 6164645f 5f6d6f64  .cache__add__mod
 00e0 756c6500 38403136 28257273 70292038  ule.8@16(%rsp) 8
 00f0 40363838 28257262 78290000 08000000  @688(%rbx)......
 0100 48000000 03000000 73746170 73647400  H.......stapsdt.
 0110 00000000 00000000 00000000 00000000  ................
 0120 00000000 00000000 73746170 00636163  ........stap.cac
 0130 68655f5f 6164645f 5f736f75 72636500  he__add__source.
 0140 38403734 34282572 62782920 38403131  8@744(%rbx) 8@11
 0150 32282572 73702900                    2(%rsp).
Comment 1 Mark Wielaard 2011-10-18 12:20:20 UTC
This is also triggered by the following testsuite failure:

Running /home/mark/src/systemtap/testsuite/semok/thirtysix.stp
starting /home/mark/src/systemtap/testsuite/semok/thirtysix.stp
spawn1 stap -p2 /home/mark/src/systemtap/testsuite/semok/thirtysix.stp
spawn stap -p2 /home/mark/src/systemtap/testsuite/semok/thirtysix.stp
WARNING: Can't parse SDT_V3 operand '(%rcx,%rax,8)': identifier '$arg1' at /home/mark/src/systemtap/testsuite/semok/thirtysix.stp:11:53
 source: probe process("stap").mark("*")? { println(@defined($arg1)?$arg1:$nosuchvar) } # valid
                                                             ^
WARNING: Can't parse SDT_V3 operand '(%rcx,%rax,8)': identifier '$arg1' at /home/mark/src/systemtap/testsuite/semok/thirtysix.stp:11:53

 source: probe process("stap").mark("*")? { println(@defined($arg1)?$arg1:$nosuchvar) } # valid

                                                             ^
semantic error: unable to find local 'nosuchvar' near pc 0x4fee20  in  <unknown> /home/mark/src/systemtap/cache.cxx ( (alternatives: $j): identifier '$nosuchvar' at :11:66
        source: probe process("stap").mark("*")? { println(@defined($arg1)?$arg1:$nosuchvar) } # valid
                                                                                 ^
Pass 2: analysis failed.  Try again with another '--vp 01' option.

semantic error: unable to find local 'nosuchvar' near pc 0x4fee20  in  <unknown> /home/mark/src/systemtap/cache.cxx ( (alternatives: $j): identifier '$nosuchvar' at :11:66

        source: probe process("stap").mark("*")? { println(@defined($arg1)?$arg1:$nosuchvar) } # valid

                                                                                 ^

Pass 2: analysis failed.  Try again with another '--vp 01' option.
wait results: 10222 exp24 0 1
FAIL: semok/thirtysix.stp
Comment 2 Frank Ch. Eigler 2011-11-11 17:02:43 UTC
commit 8095a15
Comment 3 Mark Wielaard 2011-11-12 15:05:54 UTC
(In reply to comment #2)
> commit 8095a15

After this commit sdt_misc.exp started showing the following FAIL on x86_64 with 4.6.2 20111027 (Red Hat 4.6.2-1):

FAIL: sdt_misc asm (64) asm  m

This corresponds to the following SDT note in sdt_asm.x:

  stapsdt               73  Version: 3
    PC: 0x4004cb, Base: 0x4006a8, Semaphore: 0
    Provider: provider, Name: memory, Args: '-4(%rbp) -8+4(%rbp) -8+3+1(%rbp)'

And shows up in systemtap.log as:

FAIL: memory ((7|7|1792) != 7)

(Note, this is slightly confusing, the sdt_asm.stp outputs PASS/FAIL: strings which go into systemtap.log and are different from the sdt_misc.exp PASS/FAIL strings which go into systemtap.sum)

(Note2, sdt_misc.exp is huge, it would not be a bad idea to split it up in separate .exp tests.)
Comment 4 Mark Wielaard 2011-11-14 11:31:24 UTC
Same failure on i686 with gcc 4.6.1 20110908 (Red Hat 4.6.1-9)

  stapsdt               61  Version: 3
    PC: 0x80483da, Base: 0x80484e4, Semaphore: 0
    Provider: provider, Name: memory, Args: '-4(%ebp) -8+4(%ebp) -8+3+1(%ebp)'

systemtap.log:
FAIL: memory ((7|7|1800) != 7)

systemtap.sum:
FAIL: sdt_misc asm (24) asm  m
Comment 5 Frank Ch. Eigler 2011-11-14 14:49:20 UTC
commit f7719b corrects an off-by-one error in the earlier commit.
Comment 6 Mark Wielaard 2011-11-15 09:59:44 UTC
(In reply to comment #5)
> commit f7719b corrects an off-by-one error in the earlier commit.

But seems to have cause the following new regressions:

Running /home/mark/src/systemtap/testsuite/systemtap.base/library.exp ...
FAIL: sdt_misc * (0 != 15)
FAIL: sdt_misc *libsdt* (0 != 15)
FAIL: sdt_misc ./libsdt.so (0 != 15)
FAIL: printf --ldd (0) (0 != 4)

spawn /usr/local/install/systemtap/bin/stap -c ./sdt_misc.x /home/mark/src/systemtap/testsuite/systemtap.base/library.stp ./sdt_misc.x *
WARNING: Can't parse SDT_V3 operand '-4(%rbp)': identifier '$arg1' at /home/mark/src/systemtap/testsuite/systemtap.base/library.stp:15:39
 source:   printf("In %s probe %#x\n", $$name, $arg1)
                                               ^
WARNING: Can't parse SDT_V3 operand '-16(%rbp)': identifier '$arg2' at :30:50
 source:   printf("In %s probe %#x %#x\n", $$name, $arg1, $arg2)
                                                          ^
semantic error: unable to find local 'arg1' near pc 0x87d  in  baz /home/mark/src/systemtap/testsuite/systemtap.base/sdt_misc.c ( (alternatives: $i $s): identifier '$arg1' at :15:39
        source:   printf("In %s probe %#x\n", $$name, $arg1)
                                                      ^
Pass 2: analysis failed.  Try again with another '--vp 01' option.
FAIL: sdt_misc * (0 != 15)

Note the confusing PASS/FAIL messages that don't include the test name, I'll fix that (commit 9ce0a9e).
Comment 7 Mark Wielaard 2011-11-15 10:32:47 UTC
Hopefully finally really totally fixed this now:

commit 0f7b51d6c1e968c5183a165ff3fc102357bbfc08
Author: Mark Wielaard <mjw@redhat.com>
Date:   Tue Nov 15 11:09:38 2011 +0100

    PR13313 cont'd, fix regexp for [+-]D[+-]D[+-]D(...) operand case again.
    
    The +/- before the second and third D aren't optional, but the combination
    of [+-]D as a whole is optional. Tweak regexp again.

Tested against make installcheck RUNTESTFLAGS="library.exp sdt.exp sdt_misc.exp dtrace_clone.exp dtrace_fork_exec.exp dtrace_vfork_exec.exp semok.exp"
Comment 8 Sergio Durigan Junior 2011-12-09 04:37:55 UTC
I was testing my implementation of the SystemTap probe argument parser on GDB, specifically trying to parse `(%rcx,%rax,8)'.  I decided to compare the obtained result from GDB with the result from SystemTap, and for that I have used the command specified here:

stap -e 'probe process("/home/sergio/programs/bin/stap").mark("cache__clean") { println($arg1) }'

However, I still see the error message:

WARNING: Can't parse SDT_V3 operand '(%rcx,%rax,8)': identifier '$arg1' at <input>:1:80
 source: probe process("/home/sergio/programs/bin/stap").mark("cache__clean") { println($arg1) }

            ^
semantic error: unable to find local 'arg1' near pc 0x4fb700  in  <unknown> ../../../systemtap/cache.cxx ( (alternatives: $j): identifier '$arg1' at :1:80
        source: probe process("/home/sergio/programs/bin/stap").mark("cache__clean") { println($arg1) }

             ^
Pass 2: analysis failed.  Try again with another '--vp 01' option.

I am using the following version of SystemTap:

Systemtap translator/driver (version 1.7/0.152 commit release-1.6-556-gbfffa44)
Copyright (C) 2005-2011 Red Hat, Inc. and others
This is free software; see the source for copying conditions.
enabled features: LIBRPM BOOST_SHARED_PTR TR1_UNORDERED_MAP NLS

I am not sure if I am doing something wrong, but I believe this error should have been fixed by the commits listed here, right?
Comment 9 Frank Ch. Eigler 2011-12-09 12:50:37 UTC
# stap -e 'probe process("/home/sergio/programs/bin/stap").mark("cache__clean") 
# { println($arg1) }'

Is it possible that the version of stap you invoked is not the /home/sergio/..
new one, but the older system version?  i.e., try

# /home/sergio/programs/bin/stap -e ....