Some test results on i386 and x86_64

Some test results on i386 and x86_64

[Mark Wielaard]

Here are some test results against this mornings tree (commit 6594f3f4):

Host: Linux hermans.wildebeest.org 2.6.27.21-170.2.56.fc10.i686 #1 SMP Mon Mar 2
3 23:37:54 EDT 2009 i686 i686 i386 GNU/Linux
Snapshot: version 0.9.5/0.140.90 commit 6594f3f4
Distro: Fedora release 10 (Cambridge)

# of expected passes            824
# of unexpected failures        12
# of unexpected successes       9
# of expected failures          195
# of unknown successes          2
# of known failures             10
# of untested testcases         5

FAIL: backtrace (1 0)
FAIL: backtrace-unwindsyms (1 0)
FAIL: gtod (106)
FAIL: static_uprobes types  arr_char_var
FAIL: stmt_rel line numbers
FAIL: stmt_rel wildcard (0)
FAIL: vars
FAIL: vars parms/locals
FAIL: warnings (0)
FAIL: systemtap.examples/network/dropwatch build
FAIL: systemtap.examples/network/dropwatch run
FAIL: 32-bit net1


Host: Linux dijkstra.wildebeest.org 2.6.18-128.1.6.el5xen #1 SMP Tue Mar 24 12:2
8:27 EDT 2009 x86_64 x86_64 x86_64 GNU/Linux
Snapshot: version 0.9.5/0.137 commit 6594f3f4
Distro: Red Hat Enterprise Linux Server release 5.3 (Tikanga)

# of expected passes            847
# of unexpected failures        12
# of unexpected successes       8
# of expected failures          196
# of unknown successes          4
# of known failures             8
# of untested testcases         6
# of unsupported tests          2

FAIL: backtrace (1 0)
FAIL: backtrace-unwindsyms (1 0)
FAIL: flightrec2 (log file numbers (2, 2))
FAIL: flightrec2 (log file size (4))
FAIL: itrace1 startup (eof)
FAIL: itrace2 startup (eof)
FAIL: itrace3 startup (eof)
FAIL: systemtap.base/kprobes.stp startup (eof)
FAIL: systemtap.examples/network/dropwatch build
FAIL: systemtap.examples/network/dropwatch run
FAIL: 64-bit futimes
FAIL: 32-bit futimes


Some of these are known issues:

On both i386 and x86_64:
FAIL: backtrace (1 0)
FAIL: backtrace-unwindsyms (1 0)
http://sourceware.org/bugzilla/show_bug.cgi?id=6961
"backtrace from non-pt_regs probe context"

FAIL: systemtap.examples/network/dropwatch build
FAIL: systemtap.examples/network/dropwatch run
http://sourceware.org/bugzilla/show_bug.cgi?id=10084
"systemtap.examples/network/dropwatch fails on kernels without kfree_skb
tracepoint"


On i386 (fedora/2.6.27 kernel):
FAIL: gtod (106)
http://sourceware.org/bugzilla/show_bug.cgi?id=5094
"gtod.exp fails on ppc64/i386"

FAIL: 32-bit net1
http://sourceware.org/bugzilla/show_bug.cgi?id=6991
"accept system call missed on 2.6.27"


On x86_64 (rhel/2.6.18 kernel):
FAIL: itrace1 startup (eof)
FAIL: itrace2 startup (eof)
FAIL: itrace3 startup (eof)
http://sourceware.org/bugzilla/show_bug.cgi?id=10091
"Backward compatibility for insn probe point (itrace) on older
kernels/utrace"


Not fully investigated yet:

On i386:
FAIL: static_uprobes types  arr_char_var
FAIL: stmt_rel line numbers
FAIL: stmt_rel wildcard (0)
FAIL: vars
FAIL: vars parms/locals

FAIL: warnings (0)
This crashes stap:
#0  0x00e70921 in __libdw_find_attr (die=0xbfffbd70, search_name=82, 
    codep=0xbfffbd1c, formp=0xbfffbd20)
    at /home/mark/src/elfutils/libdw/dwarf_child.c:92
#1  0x00e70248 in dwarf_attr (die=0xbfffbd70, search_name=82, 
    result=0xbfffbd1c) at /home/mark/src/elfutils/libdw/dwarf_attr.c:69
#2  0x00e711d3 in dwarf_entrypc (die=0xbfffbd70, return_addr=0xbfffbda8)
    at /home/mark/src/elfutils/libdw/dwarf_entrypc.c:65
warning: (Internal error: pc 0x811dc65 in read in psymtab, but not in
symtab.)
#3  0x0811dc66 in dwflpp::iterate_over_srcfile_lines (this=warning:
(Internal error: pc 0x811d870 in read in psymtab, but not in symtab.)
0x8919768, 
    srcfile=0x93e68cc "fs/bio.c", lines=0xbfffc494,
need_single_match=true, 
    line_type=RELATIVE, callback=0x80f1a00 <query_srcfile_line>, 
    data=0xbfffc3c4) at tapsets.cxx:1255
#4  0x080f1287 in query_cu (cudie=0xbfffc028, arg=0xbfffc3c4)
    at tapsets.cxx:4200
#5  0x080f1749 in dwflpp::iterate_over_cus () at tapsets.cxx:1103
#6  dwarf_query::query_module_dwarf (this=0xbfffc3c4) at
tapsets.cxx:3232
#7  0x080f19e8 in dwarf_query::handle_query_module (this=0xbfffc3c4)
    at tapsets.cxx:3333
#8  0x080e262a in query_module (mod=0x89198f8, name=0x8919708 "kernel", 
    addr=3225419776, arg=0xbfffc3c4) at tapsets.cxx:4443
[...]

On x86_64:
FAIL: flightrec2 (log file numbers (2, 2))
FAIL: flightrec2 (log file size (4))
FAIL: systemtap.base/kprobes.stp startup (eof)

Re: Some test results on i386 and x86_64

[Masami Hiramatsu]

Mark Wielaard wrote:
> On x86_64:
> FAIL: flightrec2 (log file numbers (2, 2))
> FAIL: flightrec2 (log file size (4))

Thanks!
Could you give me a part of systemtap.log?

-- 
Masami Hiramatsu

Software Engineer
Hitachi Computer Products (America) Inc.
Software Solutions Division

e-mail: mhiramat@redhat.com

Re: Some test results on i386 and x86_64

[Mark Wielaard]

[-- Attachment #1: Type: text/plain, Size: 269 bytes --]

On Thu, 2009-04-23 at 15:38 -0400, Masami Hiramatsu wrote:
> Mark Wielaard wrote:
> > On x86_64:
> > FAIL: flightrec2 (log file numbers (2, 2))
> > FAIL: flightrec2 (log file size (4))
> 
> Thanks!
> Could you give me a part of systemtap.log?

Attached.

Cheers,

Mark

[-- Attachment #2: systemtap.log --]
[-- Type: text/x-log, Size: 3723 bytes --]

Test Run By root on Thu Apr 23 11:05:51 2009
Native configuration is x86_64-redhat-linux-gnu

		=== systemtap tests ===

Schedule of variations:
    unix

Running target unix
Using /usr/share/dejagnu/baseboards/unix.exp as board description file for target.
Using /usr/share/dejagnu/config/unix.exp as generic interface file for target.
Using /home/mark/src/systemtap/testsuite/config/unix.exp as tool-and-target-specific interface file.

Host: Linux dijkstra.wildebeest.org 2.6.18-128.1.6.el5xen #1 SMP Tue Mar 24 12:28:27 EDT 2009 x86_64 x86_64 x86_64 GNU/Linux
Snapshot: version 0.9.5/0.137 commit 6594f3f4
Distro: Red Hat Enterprise Linux Server release 5.3 (Tikanga)

Running /home/mark/src/systemtap/testsuite/systemtap/notest.exp ...
testcase /home/mark/src/systemtap/testsuite/systemtap/notest.exp completed in 0 seconds
[...]
Running /home/mark/src/systemtap/testsuite/systemtap.base/flightrec1.exp ...
16777
PASS: flightrec1 (flight recorder option)
stapio
PASS: flightrec1 (stapio in background)
PASS: flightrec1 (output file)
testcase /home/mark/src/systemtap/testsuite/systemtap.base/flightrec1.exp completed in 0 seconds
Running /home/mark/src/systemtap/testsuite/systemtap.base/flightrec2.exp ...
16877
PASS: flightrec2 (-S option)
total 14716
   28 aclocal.m4
   16 a.out
    8 autom4te.cache
    8 buildko
    8 buildok
   68 ChangeLog
    8 config
   12 config.log
   28 config.status
  104 configure
    8 configure.ac
    8 execrc
 1000 flightlog.out.0
  100 flightlog.out.1
    8 lib
   12 libuprobes_lib.so
  100 ls_31419
   16 Makefile
    8 Makefile.am
   16 Makefile.in
    8 parseko
    8 parseok
   20 sdt.c.exe.0
   20 sdt.c.exe.1
   20 sdt.c.exe.2
   20 sdt.c.exe.3
   20 sdt.c.exe.4
   20 sdt.c.exe.5
   20 sdt.c.exe.6
   20 sdt.cxx.exe.0
   20 sdt.cxx.exe.1
   20 sdt.cxx.exe.2
   20 sdt.cxx.exe.3
   20 sdt.cxx.exe.4
   20 sdt.cxx.exe.5
   20 sdt.cxx.exe.6
    8 semko
    8 semlib
    8 semok
    8 site.exp
    8 static_uprobes.cc
    8 static_uprobes.sh
    8 systemtap
    8 systemtap.base
    8 systemtap.context
    8 systemtap.examples
   44 systemtap.log
12576 systemtap.log.orig
    8 systemtap.maps
    8 systemtap.pass1-4
    8 systemtap.printf
    8 systemtap.samples
    8 systemtap.server
    8 systemtap.stress
    8 systemtap.string
    8 systemtap.sum
   52 systemtap.sum.orig
    8 systemtap.syscall
    8 transko
    8 transok
   16 uprobes_exe
total 15536
   28 aclocal.m4
   16 a.out
    8 autom4te.cache
    8 buildko
    8 buildok
   68 ChangeLog
    8 config
   12 config.log
   28 config.status
  104 configure
    8 configure.ac
    8 execrc
 1000 flightlog.out.0
  920 flightlog.out.1
    8 lib
   12 libuprobes_lib.so
  100 ls_31419
   16 Makefile
    8 Makefile.am
   16 Makefile.in
    8 parseko
    8 parseok
   20 sdt.c.exe.0
   20 sdt.c.exe.1
   20 sdt.c.exe.2
   20 sdt.c.exe.3
   20 sdt.c.exe.4
   20 sdt.c.exe.5
   20 sdt.c.exe.6
   20 sdt.cxx.exe.0
   20 sdt.cxx.exe.1
   20 sdt.cxx.exe.2
   20 sdt.cxx.exe.3
   20 sdt.cxx.exe.4
   20 sdt.cxx.exe.5
   20 sdt.cxx.exe.6
    8 semko
    8 semlib
    8 semok
    8 site.exp
    8 static_uprobes.cc
    8 static_uprobes.sh
    8 systemtap
    8 systemtap.base
    8 systemtap.context
    8 systemtap.examples
   44 systemtap.log
12576 systemtap.log.orig
    8 systemtap.maps
    8 systemtap.pass1-4
    8 systemtap.printf
    8 systemtap.samples
    8 systemtap.server
    8 systemtap.stress
    8 systemtap.string
    8 systemtap.sum
   52 systemtap.sum.orig
    8 systemtap.syscall
    8 transko
    8 transok
   16 uprobes_exe
FAIL: flightrec2 (log file numbers (2, 2))
FAIL: flightrec2 (log file size (4))
testcase /home/mark/src/systemtap/testsuite/systemtap.base/flightrec2.exp completed in 11 seconds

Re: Some test results on i386 and x86_64

[Masami Hiramatsu]

Mark Wielaard wrote:
> On Thu, 2009-04-23 at 15:38 -0400, Masami Hiramatsu wrote:
>> Mark Wielaard wrote:
>>> On x86_64:
>>> FAIL: flightrec2 (log file numbers (2, 2))
>>> FAIL: flightrec2 (log file size (4))
>> Thanks!
>> Could you give me a part of systemtap.log?
> 
> Attached.
> 


Hmm, it seems that timer.ms(1) was not kicked so frequently
on xen-kernel.
---
 1000 flightlog.out.0
  100 flightlog.out.1
---
 1000 flightlog.out.0
  920 flightlog.out.1
---

Perhaps, timer resolution on xen-kernel may be 10ms or more?

Thank you,

-- 
Masami Hiramatsu

Software Engineer
Hitachi Computer Products (America) Inc.
Software Solutions Division

e-mail: mhiramat@redhat.com

Re: Some test results on i386 and x86_64

[Mark Wielaard]

Hi Masami,

On Fri, 2009-04-24 at 21:10 -0400, Masami Hiramatsu wrote:
> Mark Wielaard wrote:
> > On Thu, 2009-04-23 at 15:38 -0400, Masami Hiramatsu wrote:
> >> Mark Wielaard wrote:
> >>> On x86_64:
> >>> FAIL: flightrec2 (log file numbers (2, 2))
> >>> FAIL: flightrec2 (log file size (4))
> >> Thanks!
> >> Could you give me a part of systemtap.log?
> > 
> > Attached.
>
> Hmm, it seems that timer.ms(1) was not kicked so frequently
> on xen-kernel.
> ---
>  1000 flightlog.out.0
>   100 flightlog.out.1
> ---
>  1000 flightlog.out.0
>   920 flightlog.out.1
> ---
> 
> Perhaps, timer resolution on xen-kernel may be 10ms or more?

Yes, seems it counts "slower".

On my non-xen i386 machine (2.6.27.21-170.2.56.fc10.i686):
$ stap -e 'global count=0; probe timer.ms(1) { printf("%d: %d\n",
gettimeofday_ms(), count++); if (count > 10) exit(); }'
1240747341878: 0
1240747341879: 1
1240747341880: 2
1240747341881: 3
1240747341882: 4
1240747341883: 5
1240747341884: 6
1240747341885: 7
1240747341886: 8
1240747341887: 9
1240747341888: 10

But on my xen enabled x86_64 machine (2.6.18-128.1.6.el5xen):
$ stap -e 'global count=0; probe timer.ms(1) { printf("%d: %d\n",
gettimeofday_ms(), count++); if (count > 10) exit(); }'
1240747430504: 0
1240747430504: 1
1240747430514: 2
1240747430514: 3
1240747430524: 4
1240747430524: 5
1240747430524: 6
1240747430534: 7
1240747430534: 8
1240747430544: 9
1240747430544: 10

Cheers,

Mark

[PATCH] fix flightrec2.exp/stp (Re: Some test results on i386 and x86_64

[Masami Hiramatsu]

[-- Attachment #1: Type: text/plain, Size: 1356 bytes --]

Mark Wielaard wrote:
>> Perhaps, timer resolution on xen-kernel may be 10ms or more?
> 
> Yes, seems it counts "slower".
> 
> On my non-xen i386 machine (2.6.27.21-170.2.56.fc10.i686):
> $ stap -e 'global count=0; probe timer.ms(1) { printf("%d: %d\n",
> gettimeofday_ms(), count++); if (count > 10) exit(); }'
> 1240747341878: 0
> 1240747341879: 1
> 1240747341880: 2
> 1240747341881: 3
> 1240747341882: 4
> 1240747341883: 5
> 1240747341884: 6
> 1240747341885: 7
> 1240747341886: 8
> 1240747341887: 9
> 1240747341888: 10
> 
> But on my xen enabled x86_64 machine (2.6.18-128.1.6.el5xen):
> $ stap -e 'global count=0; probe timer.ms(1) { printf("%d: %d\n",
> gettimeofday_ms(), count++); if (count > 10) exit(); }'
> 1240747430504: 0
> 1240747430504: 1
> 1240747430514: 2
> 1240747430514: 3
> 1240747430524: 4
> 1240747430524: 5
> 1240747430524: 6
> 1240747430534: 7
> 1240747430534: 8
> 1240747430544: 9
> 1240747430544: 10

So, on xen, minimum timer period may be about 5ms.
In that case, this patch will help us.

This patch updates flightrec2.exp/stp

- Use stat instead of ls for getting file contents size.
- Increase timer period from 1ms to 10ms.
  (the amount of output per probe is also increased)

Thanks,

-- 
Masami Hiramatsu

Software Engineer
Hitachi Computer Products (America) Inc.
Software Solutions Division

e-mail: mhiramat@redhat.com


[-- Attachment #2: testcase-fix-flightrec-test.patch --]
[-- Type: text/plain, Size: 2075 bytes --]

PR 6930: fix flightrec2.exp to handle filesize correctly

---

 testsuite/systemtap.base/flightrec2.exp |   17 ++++++++---------
 testsuite/systemtap.base/flightrec2.stp |    4 ++--
 2 files changed, 10 insertions(+), 11 deletions(-)


diff --git a/testsuite/systemtap.base/flightrec2.exp b/testsuite/systemtap.base/flightrec2.exp
index a22ef41..d4481db 100644
--- a/testsuite/systemtap.base/flightrec2.exp
+++ b/testsuite/systemtap.base/flightrec2.exp
@@ -26,13 +26,12 @@ exec sleep 4
 set scnt 0
 set cnt1 0
 # wait for log files
-spawn ls -sk1
+eval spawn stat -c %s [glob flightlog.out.*]
 expect {
   -timeout 100
-  -re {([0-9]+) flightlog\.out\.[0-9]+} {
+  -re {[0-9]+} {
       incr cnt1;
-      if {$expect_out(1,string) <= 1028} {incr scnt}
-      # 1024 + 4(for inode blocks?)
+      if {$expect_out(buffer) <= 1048576 } {incr scnt}
       exp_continue}
   timeout { fail "$test (logfile timeout)"}
 }
@@ -40,12 +39,12 @@ wait
 exec sleep 3
 set cnt2 0
 # wait for log files
-spawn ls -sk1
+eval spawn stat -c %s [glob flightlog.out.*]
 expect {
   -timeout 100
-  -re {([0-9]+) flightlog\.out\.[0-9]+} {
+  -re {[0-9]+} {
       incr cnt2;
-      if {$expect_out(1,string) <= 1028} {incr scnt}
+      if {$expect_out(buffer) <= 1048576 } {incr scnt}
       exp_continue}
   timeout { fail "$test (logfile timeout)"}
 }
@@ -57,10 +56,10 @@ if {$cnt1 == 3 && $cnt2 == 3} {
   fail "$test (log file numbers ($cnt1, $cnt2))"
 }
 # check logfile size
-if {$scnt == 6} {
+if {$scnt == $cnt1 + $cnt2 } {
     pass "$test (log file size limitation)"
 } else {
-  fail "$test (log file size ($scnt))"
+  fail "$test (log file size ($scnt != $cnt1 + $cnt2))"
 }
 exec kill -TERM $pid
 # wait for exiting...
diff --git a/testsuite/systemtap.base/flightrec2.stp b/testsuite/systemtap.base/flightrec2.stp
index 9d745f4..f42c9b8 100644
--- a/testsuite/systemtap.base/flightrec2.stp
+++ b/testsuite/systemtap.base/flightrec2.stp
@@ -1,5 +1,5 @@
-probe timer.ms(1)
+probe timer.ms(10)
 {
-  for (j = 0; j < 100; j++)
+  for (j = 0; j < 1000; j++)
     printf("1234567890\n")
 }

Re: [PATCH] fix flightrec2.exp/stp (Re: Some test results on i386 and x86_64

[Mark Wielaard]

Hi Masami,

On Mon, 2009-04-27 at 15:22 -0400, Masami Hiramatsu wrote:
> So, on xen, minimum timer period may be about 5ms.
> In that case, this patch will help us.
> 
> This patch updates flightrec2.exp/stp
> 
> - Use stat instead of ls for getting file contents size.
> - Increase timer period from 1ms to 10ms.
>   (the amount of output per probe is also increased)

With this the testcase PASSes for me:

Host: Linux gnu 2.6.18-128.1.6.el5xen #1 SMP Wed Apr 1 09:53:14 EDT 2009
x86_64 x86_64 x86_64 GNU/Linux
Snapshot: version 0.9.7/0.137 commit release-0.9.7-15-g9f38e65
Distro: CentOS release 5.3 (Final)

Running /home/mark/src/systemtap/testsuite/systemtap.base/flightrec2.exp ...

		=== systemtap Summary ===

# of expected passes		3

Thanks,

Mark