From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (qmail 2063 invoked by alias); 20 Oct 2006 19:26:48 -0000 Received: (qmail 2056 invoked by uid 22791); 20 Oct 2006 19:26:47 -0000 X-Spam-Status: No, hits=-2.7 required=5.0 tests=AWL,BAYES_00,SPF_HELO_PASS,SPF_PASS X-Spam-Check-By: sourceware.org Received: from mx1.redhat.com (HELO mx1.redhat.com) (66.187.233.31) by sourceware.org (qpsmtpd/0.31) with ESMTP; Fri, 20 Oct 2006 19:26:34 +0000 Received: from int-mx1.corp.redhat.com (int-mx1.corp.redhat.com [172.16.52.254]) by mx1.redhat.com (8.12.11.20060308/8.12.11) with ESMTP id k9KJQUEP019695; Fri, 20 Oct 2006 15:26:30 -0400 Received: from pobox.hsv.redhat.com (pobox.hsv.redhat.com [172.16.16.12]) by int-mx1.corp.redhat.com (8.13.1/8.13.1) with ESMTP id k9KJQUVZ028403; Fri, 20 Oct 2006 15:26:30 -0400 Received: from [172.16.17.170] (dhcp-170.hsv.redhat.com [172.16.17.170]) by pobox.hsv.redhat.com (8.12.11.20060308/8.12.11) with ESMTP id k9KJQTad027240; Fri, 20 Oct 2006 15:26:29 -0400 Message-ID: <453922E8.4000608@redhat.com> Date: Fri, 20 Oct 2006 19:26:00 -0000 From: David Smith User-Agent: Thunderbird 1.5.0.7 (X11/20061004) MIME-Version: 1.0 To: "Stone, Joshua I" CC: "Frank Ch. Eigler" , systemtap@sources.redhat.com Subject: Re: precompiled probing scenarios References: In-Reply-To: Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit X-IsSubscribed: yes Mailing-List: contact systemtap-help@sourceware.org; run by ezmlm Precedence: bulk List-Subscribe: List-Post: List-Help: , Sender: systemtap-owner@sourceware.org X-SW-Source: 2006-q4/txt/msg00221.txt.bz2 Stone, Joshua I wrote: > On Friday, October 20, 2006 6:50 AM, David Smith wrote: >> Frank Ch. Eigler wrote: >>>> Note that currently several tests in the testsuite fail after a >>>> first run to seed the cache because they don't expect to see the >>>> skip from pass 2 to pass 5. >>> How do you mean they fail? -p3 or -p4 should still work. >> Here's what goes on. The '-p3' and '-p4' options still work. But, >> several run ('-p5') tests use testsuite/lib/stap_run.exp or >> testsuite/lib/stap_run2.exp. Those two tcl files expect to see "Pass >> [12345]" in the output. They get confused when only seeing "Pass >> [125]" and then think the test has timed out. > > Would it make sense to print "dummy" pass 3/4 messages when a cached > version is used? Something like: > > Pass 1: parsed user script and 53 library script(s) in > 310usr/0sys/326real ms. > Pass 2: analyzed script: 1 probe(s), 0 function(s), 0 global(s) in > 10usr/0sys/5real ms. > Pass 3: (cached) in 0usr/0sys/0real ms. > Pass 4: (cached) in 0usr/0sys/0real ms. > Pass 5: starting run. Actually I've found out that the lack of "Pass [34]" wasn't the problem, it was the extra cache output messages that was confusing the testsuite. Here's what the output now looks like (non-cached and cached): ===== # stap -v -e 'probe begin { log("hi") }' Pass 1: parsed user script and 53 library script(s) in 680usr/10sys/692real ms. Pass 2: analyzed script: 1 probe(s), 1 function(s), 0 global(s) in 10usr/0sys/11real ms. Pass 3: translated to C into "/tmp/stapYrsXWC/stap_d833fd040735ddde57a23bebb4456542_201.c" in 140usr/90sys/245real ms. Pass 4: compiled C into "stap_d833fd040735ddde57a23bebb4456542_201.ko" in 5030usr/550sys/5587real ms. Copying /tmp/stapYrsXWC/stap_d833fd040735ddde57a23bebb4456542_201.ko to /home/dsmith/.stap_cache/d/8/stap_d833fd040735ddde57a23bebb4456542_201.ko Copying /tmp/stapYrsXWC/stap_d833fd040735ddde57a23bebb4456542_201.c to /home/dsmith/.stap_cache/d/8/stap_d833fd040735ddde57a23bebb4456542_201.c Pass 5: starting run. hi Pass 5: run completed in 10usr/40sys/4634real ms. # stap -v -e 'probe begin { log("hi") }' Pass 1: parsed user script and 53 library script(s) in 670usr/20sys/692real ms. Pass 2: analyzed script: 1 probe(s), 1 function(s), 0 global(s) in 10usr/0sys/11real ms. Using cached result "/home/dsmith/.stap_cache/d/8/stap_d833fd040735ddde57a23bebb4456542_201.ko" as "/tmp/stapJFisJO/stap_d833fd040735ddde57a23bebb4456542_201.ko" Pass 5: starting run. hi Pass 5: run completed in 0usr/40sys/1656real ms. ===== > The timing info doesn't need to be hardcoded zero, I just expect it > would be very small. > > Side question - do you still use caching when someone calls '-p3' or > '-p4'? And with verbosity increased, what would this output, given that > you're not actually doing the work? (e.g., you wouldn't have a compiler > output on a cached pass-4.) A module only gets added to the cache if pass 4 completes successfully. A module (currently) gets pulled from the cache after pass 2, even if '-p3' or '-p4' was specified on the command line. -- David Smith dsmith@redhat.com Red Hat http://www.redhat.com 256.217.0141 (direct) 256.837.0057 (fax)