This is the mail archive of the systemtap@sourceware.org mailing list for the systemtap project.


Index Nav: [Date Index] [Subject Index] [Author Index] [Thread Index]
Message Nav: [Date Prev] [Date Next] [Thread Prev] [Thread Next]
Other format: [Raw text]

Re: some test results


Hi,

Since it seems dejazilla is still not accepting my systemtap.sum files,
here is another quick summary of some test results, this time on fedora
15, i686:

Host: Linux hermans.wildebeest.org 2.6.38.6-27.fc15.i686 #1 SMP Sun May
15 17:57:13 UTC 2011 i686 i686 i386 GNU/Linux
Snapshot: version 1.6/0.148.90 commit release-1.5-10-gb05c6cb
GCC: 4.6.0 [gcc (GCC) 4.6.0 20110509 (Red Hat 4.6.0-7)]
Distro: Fedora release 15 (Lovelock)

                === systemtap Summary ===

# of expected passes            1686
# of unexpected failures        56
# of unexpected successes       8
# of expected failures          271
# of known failures             3
# of untested testcases         53

This one has about 100 PASSes less than the f14 x86_64 run (most likely
because x86_64 also does some 32bit tests) and about 20 more FAILs.

FAIL: cmd_parse8: unexpected timeout

This is "stap -l vm.*" which takes a very long time on this machine the
first time it is ran (without .systemtap/cache).

real	1m11.438s
user	0m45.544s
sys	0m23.817s

After the cache has been generated, it takes 2 seconds.

FAIL: gtod (102)

This seems a flaky test on this machine, it always fails around 100.

FAIL: implicitptr-O1
FAIL: implicitptr-O2
FAIL: implicitptr-O3

All variants of:
Got "semantic error: not accessible at this address (0x8048460,
dieoffset: 0xed): identifier '$b'
at /home/mark/src/systemtap/testsuite/systemtap.base/implicitptr.stp:20:22"

Where [ed] is:
 [    ed]      formal_parameter
               name                 (string) "b"
               decl_file            (data1) 1
               decl_line            (data1) 27
               type                 (ref4) [   11a]
               location             (data4) location list [    1f]
with location list [1f]:
 [    1f]  0x08048450 <add>..0x0804845d <add+0xd> [   0] reg2

So indeed 0x8048460 is just beyond where the location list says '$b' can
be found. If we look at the disassembler of add:

Dump of assembler code for function add:
   0x08048450 <+0>:	push   %esi
   0x08048451 <+1>:	push   %ebx
   0x08048452 <+2>:	mov    (%edx),%esi
   0x08048454 <+4>:	mov    (%eax),%ebx
   0x08048456 <+6>:	mov    (%esi),%esi
   0x08048458 <+8>:	add    %esi,(%ebx)
   0x0804845a <+10>:	mov    0x4(%edx),%edx
   0x0804845d <+13>:	add    %edx,0x4(%eax)
   0x08048460 <+16>:	nop
   0x08048461 <+17>:	addl   $0x1,0x8049774(,%ecx,4)
   0x08048469 <+25>:	addl   $0x1,0x8049778(,%ecx,4)
   0x08048471 <+33>:	nop
   0x08048472 <+34>:	pop    %ebx
   0x08048473 <+35>:	addl   $0x1,0x804977c(,%ecx,4)
   0x0804847b <+43>:	pop    %esi
   0x0804847c <+44>:	ret    
End of assembler dump.

then we see 0x08048460 is our marker:

static inline void
add (struct S *a, struct S *b, int c)
{
  *a->x += *b->x;
  a->y += b->y;
 l1: MARK (add_l1);
  u[c + 0]++;
  a = (struct S *) 0;
  u[c + 1]++;
  a = b;
 l2: MARK (add_l2);
  u[c + 2]++;
}

where MARK is defined as:

#define MARK(name) STAP_PROBE(implicitptr, name)

And the probe in question is defined as:

probe process(@1).mark("add_*")
{
  printf("*a->x=%d, a->y=%d, *b->x=%d, b->y=%d\n",
         $a->x[0], $a->y, $b->x[0], $b->y);
}

FAIL: printf --ldd

This test case (library.exp) is x86_64 specific. It expects to find:

    -re {Added -d '/lib64/libc.so.6' due to 'libc.so.6'} {incr ok; exp_continue }
    -re {Added -d '/lib64/ld-linux-x86-64.so.2'} {incr ok; exp_continue }
    -re {Added -d '/lib64/libc.so.6' due to 'libc.so.6'} {incr ok; exp_continue }
    -re {Added -d '/lib64/ld-linux-x86-64.so.2'} {incr ok; exp_continue }
    -re {Added -d '/lib64/libc.so.6' due to 'libc.so.6'} {incr ok; exp_continue }
    -re {Added -d '/lib64/ld-linux-x86-64.so.2'} {incr ok; exp_continue }
    -re {Added -d '/lib64/ld-linux-x86-64.so.2'} {incr ok; exp_continue }

While in i686 it produces:

Added -d '/lib/libc.so.6' due to 'libc.so.6'
Added -d '/lib/ld-linux.so.2'
Added -d '/lib/libc.so.6' due to 'libc.so.6'
Added -d '/lib/ld-linux.so.2'
Added -d '/lib/libc.so.6' due to 'libc.so.6'
Added -d '/lib/ld-linux.so.2'
Added -d '/lib/ld-linux.so.2'

FAIL: ptridx (0)

spawn stap /home/mark/src/systemtap/testsuite/systemtap.base/ptridx.stp -c ./ptridx.exe -w
17, 23
a 17, 23
p 17, 23
FAIL: ptridx (0)

Which looks to me should match:
-re {^[ap] (0x\[0-9a-f]+ => )?17, 23\r\n} { incr ok; exp_continue }
but it doesn't for some reason...

FAIL: rep_ret-default (2, 1, 0)
FAIL: sdt_misc (2) shared V2_kprobe
FAIL: sdt_misc (0) V2_kprobe shared attach
FAIL: sdt_misc (2) shared V2_uprobe
FAIL: sdt_misc (0) V2_uprobe shared attach

These seem to match the failures seen on x86_64.

FAIL: setjmp  
FAIL: setjmp  -D_FORTIFY_SOURCE=2
FAIL: setjmp -DSIGJMP 
FAIL: setjmp -DSIGJMP -D_FORTIFY_SOURCE=2
FAIL: setjmp -DUNDERJMP 
FAIL: setjmp -DUNDERJMP -D_FORTIFY_SOURCE=2

stap -l yields: process("/lib/libc-2.13.90.so").mark("longjmp")?
process("/lib/libc-2.13.90.so").mark("longjmp_target")?
process("/lib/libc-2.13.90.so").mark("setjmp")?
executing: stap -w
--ldd /home/mark/src/systemtap/testsuite/systemtap.base/setjmp.stp
setjmp.exe ./setjmp.exe -c ./setjmp.exe
FAIL: setjmp  

So, the markers seem to be found, but then they aren't triggered?

FAIL: stmt_rel stmt_rel (0)

spawn stap -c ./stmt_rel.x -e probe process("./stmt_rel.x").statement("Move@stmt_rel.c+1") {printf("Move %d\n",$s1)}

Execution by hand gives:

semantic error: libdw failure (dwarf_entrypc): no error
semantic error: no match while resolving probe point process("./stmt_rel.x").statement("Move@stmt_rel.c+1")

FAIL: vta-test.c compile default

spawn -ignore SIGHUP gcc /home/mark/src/systemtap/testsuite/systemtap.base/vta-test.c -g -O2 -isystem/home/mark/src/systemtap/testsuite -isystem/usr/local/install/systemtap/include default -lm -o vta-testdefault.exe
gcc: error: default: No such file or directory
compiler exited with status 1
output is:
gcc: error: default: No such file or directory

Which comes from:

# Force 64-bit (when necessary) to be sure of what we're testing.
switch -regexp $::tcl_platform(machine) {
    {^(x86_64|ppc64|s390x)$} { set arches [list "-m64"] }
    default { set arches [list "default"] }
}
[...]
    if {$arch != "-default"} {
        set test_flags "$test_flags additional_flags=$arch"
    }

ehe? How did this ever work? I pushed the trivial fix for that.
But then...

line 1: expected "a: {17, 23}"
Got "semantic error: failed to retrieve location attribute for local 'a' (dieoffset: 0xef): identifier '$a' at /home/mark/src/systemtap/testsuite/systemtap.base/vta-test.stp:2:27"

Needs more investigation. This is the same failure as on x86_64.

FAIL: warnings (0)

spawn stap -p4 /home/mark/src/systemtap/testsuite/systemtap.base/warnings.stp
semantic error: multiple addresses for fs/bio.c:256 (try fs/bio.c:254 or fs/bio.
c:257)
semantic error: no match while resolving probe point kernel.statement("bio_init@
fs/bio.c+1")
semantic error: no match while resolving probe point probea

FAIL: mark-uprobesgcc-O3default-debug-uprobeslibgcc-O3default-prelink-sep-debug_uprobeslibgcc-O3default-prelink-sep-debug (3)
FAIL: mark-uprobesgcc-O3default-sep-debug-uprobeslibgcc-O3default-prelink-sep-debug_uprobeslibgcc-O3default-prelink-sep-debug (3)
FAIL: mark-uprobesgcc-O3default-pie-debug-uprobeslibgcc-O3default-prelink-sep-debug_uprobeslibgcc-O3default-prelink-sep-debug (3)
FAIL: mark-uprobesgcc-O3default-pie-sep-debug-uprobeslibgcc-O3default-prelink-sep-debug_uprobeslibgcc-O3default-prelink-sep-debug (3)

Looks like the same (unidentified) issue as on x86_64.

FAIL: pthreadprobes cond_broadcast
FAIL: pthreadprobes cond_init
FAIL: pthreadprobes cond_signal
FAIL: pthreadprobes cond_timedwait
FAIL: pthreadprobes cond_wait
FAIL: pthreadprobes mutex_acquired
FAIL: pthreadprobes mutex_destroy
FAIL: pthreadprobes mutex_entry
FAIL: pthreadprobes mutex_init
FAIL: pthreadprobes mutex_release
FAIL: pthreadprobes mutex_timedlock_acquired
FAIL: pthreadprobes mutex_timedlock_entry
FAIL: pthreadprobes pthread_create
FAIL: pthreadprobes pthread_join
FAIL: pthreadprobes pthread_join_ret
FAIL: pthreadprobes pthread_start
FAIL: pthreadprobes rdlock_entry
FAIL: pthreadprobes wrlock_entry

Apparently all these probes can be found, but then aren't triggered?

FAIL: buildok/nfs_proc-detailed.stp

semantic error: unable to find local 'task' near pc 0x4fa12  in  nfs_read_done f
s/nfs/proc.c ( (alternatives: $data): identifier '$task' at /usr/local/install/s
ystemtap/share/systemtap/tapset/nfs_proc.stp:803:11
        source:         status = $task->tk_status
                                 ^
semantic error: unable to find local 'task' near pc 0x4fa12  in  nfs_read_done f
s/nfs/proc.c ( (alternatives: $data): identifier '$task' at /usr/local/install/s
ystemtap/share/systemtap/tapset/nfs_proc.stp:803:11

        source:         status = $task->tk_status

                                 ^
semantic error: unable to find local 'task' near pc 0x4f9bc  in  nfs_write_done 
fs/nfs/proc.c ( (alternatives: $data): identifier '$task' at :1039:11
        source:         status = $task->tk_status
                                 ^
semantic error: unable to find local 'task' near pc 0x54a11  in  nfs3_write_done
 fs/nfs/nfs3proc.c ( (alternatives: $data): identifier '$task' at :1070:11
        source:         status = $task->tk_status
                                 ^

semantic error: unable to find local 'task' near pc 0x4f9bc  in  nfs_write_done 
fs/nfs/proc.c ( (alternatives: $data): identifier '$task' at :1039:11

        source:         status = $task->tk_status

                                 ^

semantic error: unable to find local 'task' near pc 0x54a11  in  nfs3_write_done
 fs/nfs/nfs3proc.c ( (alternatives: $data): identifier '$task' at :1070:11

        source:         status = $task->tk_status

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

Pass 2: analysis failed.  Try again with another '--vp 01' option.
wait results: 21115 exp14 0 1


FAIL: buildok/nfsd-detailed.stp

spawn stap -p4 /home/mark/src/systemtap/testsuite/buildok/nfsd-detailed.stp
semantic error: unable to find local 'rqstp' near pc 0x2476e  in  nfsd_open fs/nfsd/vfs.c ( (alternatives: $filp $access $fhp): identifier '$rqstp' at /usr/local/install/systemtap/share/systemtap/tapset/nfsd.stp:1016:33
        source:         client_ip = addr_from_rqst_str($rqstp)
                                                       ^
semantic error: unable to find local 'type' near pc 0x2476e  in  nfsd_open fs/nfsd/vfs.c ( (alternatives: $filp $access $fhp): identifier '$type' at :1020:9
        source:         type = $type
                               ^
semantic error: unable to find local 'rqstp' near pc 0x2476e  in  nfsd_open fs/nfsd/vfs.c ( (alternatives: $filp $access $fhp): identifier '$rqstp' at /usr/local/install/systemtap/share/systemtap/tapset/nfsd.stp:1016:33

        source:         client_ip = addr_from_rqst_str($rqstp)

                                                       ^

semantic error: unable to find local 'type' near pc 0x2476e  in  nfsd_open fs/nfsd/vfs.c ( (alternatives: $filp $access $fhp): identifier '$type' at :1020:9

        source:         type = $type

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

Pass 2: analysis failed.  Try again with another '--vp 01' option.
wait results: 21541 exp14 0 1


FAIL: buildok/rpc-detailed.stp

spawn stap -p4 /home/mark/src/systemtap/testsuite/buildok/rpc-detailed.stp
WARNING: cannot probe .return of 1 inlined functions  rpc_release_task
WARNING: cannot probe .return of 1 inlined functions  rpc_release_task
semantic error: unable to find local 'clnt' near pc 0x11c85  in  rpc_call_sync n
et/sunrpc/clnt.c (): identifier '$clnt' at /usr/local/install/systemtap/share/sy
stemtap/tapset/rpc.stp:436:29
        source:         servername = kernel_string($clnt->cl_server)
                                                   ^
semantic error: unable to find local 'clnt' near pc 0x11c85  in  rpc_call_sync n
et/sunrpc/clnt.c (): identifier '$clnt' at :437:27
        source:         progname = kernel_string($clnt->cl_protname)
                                                 ^
semantic error: unable to find local 'clnt' near pc 0x11c85  in  rpc_call_sync n
et/sunrpc/clnt.c (): identifier '$clnt' at :439:24
        source:         vers = vers_from_clnt($clnt)
                                              ^
semantic error: unable to find local 'clnt' near pc 0x11c85  in  rpc_call_sync n
et/sunrpc/clnt.c (): identifier '$clnt' at :442:23
        source:         xid  = xid_from_clnt($clnt)
                                             ^
semantic error: unable to find local 'flags' near pc 0x11c85  in  rpc_call_sync 
net/sunrpc/clnt.c (): identifier '$flags' at :453:10
        source:         flags = $flags
                                ^

semantic error: unable to find local 'clnt' near pc 0x11c85  in  rpc_call_sync n
et/sunrpc/clnt.c (): identifier '$clnt' at /usr/local/install/systemtap/share/sy
stemtap/tapset/rpc.stp:436:29

        source:         servername = kernel_string($clnt->cl_server)

                                                   ^

semantic error: unable to find local 'clnt' near pc 0x11c85  in  rpc_call_sync n
et/sunrpc/clnt.c (): identifier '$clnt' at :437:27

        source:         progname = kernel_string($clnt->cl_protname)

                                                 ^

semantic error: unable to find local 'clnt' near pc 0x11c85  in  rpc_call_sync n
et/sunrpc/clnt.c (): identifier '$clnt' at :439:24

        source:         vers = vers_from_clnt($clnt)

                                              ^

semantic error: unable to find local 'clnt' near pc 0x11c85  in  rpc_call_sync net/sunrpc/clnt.c (): identifier '$clnt' at :442:23

        source:         xid  = xid_from_clnt($clnt)

                                             ^

semantic error: unable to find local 'flags' near pc 0x11c85  in  rpc_call_sync net/sunrpc/clnt.c (): identifier '$flags' at :453:10

        source:         flags = $flags

                                ^
semantic error: unable to find local 'clnt' near pc 0x11c85  in  rpc_call_sync net/sunrpc/clnt.c (): identifier '$clnt' at :438:24
        source:         prog = prog_from_clnt($clnt)
                                              ^
semantic error: unable to find local 'clnt' near pc 0x11c85  in  rpc_call_sync net/sunrpc/clnt.c (): identifier '$clnt' at :440:24
        source:         prot = prot_from_clnt($clnt)
                                              ^
semantic error: unable to find local 'clnt' near pc 0x11c85  in  rpc_call_sync net/sunrpc/clnt.c (): identifier '$clnt' at :441:24
        source:         port = port_from_clnt($clnt)
                                              ^
semantic error: unable to find local 'clnt' near pc 0x11c85  in  rpc_call_sync net/sunrpc/clnt.c (): identifier '$clnt' at :446:22
        source:                    : (atomic_read(&$clnt->cl_count) == 0)))
                                            
semantic error: unable to find local 'clnt' near pc 0x11c85  in  rpc_call_sync net/sunrpc/clnt.c (): identifier '$clnt' at :438:24

        source:         prog = prog_from_clnt($clnt)

                                              ^

semantic error: unable to find local 'clnt' near pc 0x11c85  in  rpc_call_sync net/sunrpc/clnt.c (): identifier '$clnt' at :440:24

        source:         prot = prot_from_clnt($clnt)

                                              ^

semantic error: unable to find local 'clnt' near pc 0x11c85  in  rpc_call_sync net/sunrpc/clnt.c (): identifier '$clnt' at :441:24

        source:         port = port_from_clnt($clnt)

                                              ^

semantic error: unable to find local 'clnt' near pc 0x11c85  in  rpc_call_sync net/sunrpc/clnt.c (): identifier '$clnt' at :446:22

        source:                    : (atomic_read(&$clnt->cl_count) == 0)))
       ^
semantic error: unable to find local 'msg' near pc 0x11c85  in  rpc_call_sync net/sunrpc/clnt.c (): identifier '$msg' at :448:23
        source:         proc = proc_from_msg($msg)
                                             ^

                                                   ^

semantic error: unable to find local 'msg' near pc 0x11c85  in  rpc_call_sync net/sunrpc/clnt.c (): identifier '$msg' at :448:23

        source:         proc = proc_from_msg($msg)

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


FAIL: buildok/twentyseven.stp

semantic error: cannot expand unknown type: identifier 'request' at /usr/local/i
nstall/systemtap/share/systemtap/tapset/i386/aux_syscalls.stp:45:41
        source: function _ptrace_return_arch_prctl_addr(request, addr, data)
                                                        ^
Pass 3: translation failed.  Try again with another '--vp 001' option.
semantic error: cannot expand unknown type: identifier 'request' at /usr/local/i
nstall/systemtap/share/systemtap/tapset/i386/aux_syscalls.stp:45:41

        source: function _ptrace_return_arch_prctl_addr(request, addr, data)

                                                        ^

Pass 3: translation failed.  Try again with another '--vp 001' option.
wait results: 16447 exp14 0 1

Probably should explicitly mark request as string, dunno why though.

FAIL: semok/thirtynine.stp

Same as on x86_64:

spawn stap -p2 /home/mark/src/systemtap/testsuite/semok/thirtynine.stp
semantic error: not accessible at this address (0xc07d4e27, dieoffset: 0x5c18c1)
: identifier '$prev' at /home/mark/src/systemtap/testsuite/semok/thirtynine.stp:
6:40
        source:   printf("switch from=0x%x to=0x%x\n", $prev, $next)
                                                       ^
Pass 2: analysis failed.  Try again with another '--vp 01' option.
semantic error: not accessible at this address (0xc07d4e27, dieoffset: 0x5c18c1)
: identifier '$prev' at /home/mark/src/systemtap/testsuite/semok/thirtynine.stp:
6:40

        source:   printf("switch from=0x%x to=0x%x\n", $prev, $next)

                                                       ^

Pass 2: analysis failed.  Try again with another '--vp 01' option.
wait results: 24677 exp14 0 1

FAIL: RING_BUFFER startup (eof)

Same compile error as on x86_64:

Pass 3: translated to C into "/tmp/stapU1MYp2/stap_a40eef43d06f6bfd32a8928a4714d9a2_840.c" using 25000virt/14536res/2868shr kb, in 0usr/0sys/1real ms.
In file included from /usr/local/install/systemtap/share/systemtap/runtime/transport/transport.c:56:0,
                 from /usr/local/install/systemtap/share/systemtap/runtime/print.c:18,
                 from /usr/local/install/systemtap/share/systemtap/runtime/runtime.h:128,
                 from /tmp/stapU1MYp2/stap_a40eef43d06f6bfd32a8928a4714d9a2_840.c:59:
/usr/local/install/systemtap/share/systemtap/runtime/transport/ring_buffer.c: In function â_stp_ring_buffer_consumeâ:
/usr/local/install/systemtap/share/systemtap/runtime/transport/ring_buffer.c:255:2: error: too few arguments to function âring_buffer_consumeâ
include/linux/ring_buffer.h:114:1: note: declared here
/usr/local/install/systemtap/share/systemtap/runtime/transport/ring_buffer.c: In function â_stp_peek_next_eventâ:
/usr/local/install/systemtap/share/systemtap/runtime/transport/ring_buffer.c:291:3: error: too few arguments to function âring_buffer_peekâ
include/linux/ring_buffer.h:111:1: note: declared here
/usr/local/install/systemtap/share/systemtap/runtime/transport/ring_buffer.c: In function â_stp_buffer_iter_startâ:
/usr/local/install/systemtap/share/systemtap/runtime/transport/ring_buffer.c:398:7: error: passing argument 1 of âring_buffer_read_startâ from incompatible pointer type [-Werror]
include/linux/ring_buffer.h:120:6: note: expected âstruct ring_buffer_iter *â but argument is of type âstruct ring_buffer *â
/usr/local/install/systemtap/share/systemtap/runtime/transport/ring_buffer.c:398:7: error: too many arguments to function âring_buffer_read_startâ
include/linux/ring_buffer.h:120:6: note: declared here
/usr/local/install/systemtap/share/systemtap/runtime/transport/ring_buffer.c:398:7: error: void value not ignored as it ought to be
cc1: all warnings being treated as errors

make[4]: *** [/tmp/stapU1MYp2/stap_a40eef43d06f6bfd32a8928a4714d9a2_840.o] Error 1
make[3]: *** [_module_/tmp/stapU1MYp2] Error 2

FAIL: 32-bit dup nd_syscall
FAIL: 32-bit eventfd nd_syscall
FAIL: 32-bit inotify nd_syscall
FAIL: 32-bit net1 nd_syscall
FAIL: 32-bit pipe nd_syscall
FAIL: 32-bit poll nd_syscall
FAIL: 32-bit signalfd nd_syscall

I think these are "expected".


Index Nav: [Date Index] [Subject Index] [Author Index] [Thread Index]
Message Nav: [Date Prev] [Date Next] [Thread Prev] [Thread Next]