From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (qmail 11530 invoked by alias); 8 Aug 2016 14:58:49 -0000 Mailing-List: contact systemtap-help@sourceware.org; run by ezmlm Precedence: bulk List-Id: List-Subscribe: List-Post: List-Help: , Sender: systemtap-owner@sourceware.org Received: (qmail 11522 invoked by uid 89); 8 Aug 2016 14:58:48 -0000 Authentication-Results: sourceware.org; auth=none X-Virus-Found: No X-Spam-SWARE-Status: No, score=-2.4 required=5.0 tests=BAYES_00,RP_MATCHES_RCVD,SPF_HELO_PASS autolearn=ham version=3.3.2 spammy=U*dsmith, sk:dsmith, sk:dsmith@, dsmith@redhat.com X-HELO: mx1.redhat.com Received: from mx1.redhat.com (HELO mx1.redhat.com) (209.132.183.28) by sourceware.org (qpsmtpd/0.93/v0.84-503-g423c35a) with (AES256-GCM-SHA384 encrypted) ESMTPS; Mon, 08 Aug 2016 14:58:46 +0000 Received: from int-mx10.intmail.prod.int.phx2.redhat.com (int-mx10.intmail.prod.int.phx2.redhat.com [10.5.11.23]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by mx1.redhat.com (Postfix) with ESMTPS id 46C1C8553C; Mon, 8 Aug 2016 14:58:45 +0000 (UTC) Received: from t540p.usersys.redhat.com ([10.15.1.188]) by int-mx10.intmail.prod.int.phx2.redhat.com (8.14.4/8.14.4) with ESMTP id u78Ewibn025595 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO); Mon, 8 Aug 2016 10:58:44 -0400 Subject: Re: Some newbie questions To: Avi Kivity , systemtap@sourceware.org References: From: David Smith Message-ID: Date: Mon, 08 Aug 2016 14:58:00 -0000 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:45.0) Gecko/20100101 Thunderbird/45.2.0 MIME-Version: 1.0 In-Reply-To: Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-IsSubscribed: yes X-SW-Source: 2016-q3/txt/msg00137.txt.bz2 On 08/07/2016 03:07 AM, Avi Kivity wrote: > Hello, > > A few newbie questions. > > 1. Static library support > > I am writing a static library, and would like to ship some scripts with > the library for its consumers. The library is named "seastar" and one > of the consumers is named "scylla". > > What should I write as the process name in the script? As the writer of > the library, I don't know the name of the process that will be consuming > the library. The consumer shouldn't have to write those scripts. I > could play sed games to adjust the scripts, but it's very sad to have to > do this. The tricky part here is that your library is static. With a shared library, you could do something like: probe process.library("libseastar.so").function("FOO") { } which would get probe hits for any process that uses that shared library. For a statically linked library, you can't do that. Off the top of my head, I don't see any solution other than your '@1' parameter idea. > 2. Inlined functions > > From the manual pages, it seems that inlined functions can be probed > (minus the .return probe), but I just get an error: > > semantic error: while resolving probe point: identifier 'process' at > script/home/avi/seastar/debug/task-latency.stap:3:7 > source: probe process("scylla").function("reactor::run_tasks()") { > ^ > > semantic error: no match (similar functions: > _ZN7reactor14run_exit_tasksEv, statfs, dup, mkdir, ntohs) We're at the mercy of the compiler and the quality of the debuginfo it produces here when looking for inlined functions. If you want to investigate further here, you'll need to do the following: # eu-readelf -N --debug-dump=info scylla > scylla.log In scylla.log, look and see if you can find a subprogram with the name of the function you are interested in. > I will note that "mkdir" does not sound very similar to > "reactor::run_tasks()" (but I am not a native speaker). Actually, to my native speaker's eyes, none of the suggested functions look that close. The way the levenshtein suggestive feature works is that we report the top 5 scoring functions. I'd bet in this case the scores were all bad, but these were the top 5 of the scores. > 3. Process CPU timers > > (more of a feature request) > > I'm trying to find causes of latency in my program. To do that, I'm > running a periodic timer and checking whether a function takes more time > than some threshold. > > Ideally, I'd be able to arm the timer on the function entry point and > disarm it on exit, rather than have it run continuously; this would need > to be a per-thread cpu-time timer (e.g. CLOCK_THREAD_CPUTIME_ID)/ > > Here's my current script for reference ("running" and "start_time" need > to become maps for it to be thread-safe): > > #!/usr/bin/stap > > global start_time > global running > > probe begin { > running = 0 > } > > probe > process("/home/avi/urchin/build/release/scylla").mark("reactor_run_tasks_start") > { > start_time = gettimeofday_us() > running = 1 > } > > probe > process("/home/avi/urchin/build/release/scylla").mark("reactor_run_tasks_end") > { > running = 0 > } > > probe timer.ms(10) { > now = gettimeofday_us() > if (running && (now - start_time) > 30000) { > printf("detected tasks running for >30ms\n") > print_usyms(ubacktrace()) > } > } > > I'd appreciate any tips as to whether there's a better way to do this. The above isn't really going to work well, for several reasons: 1) You've only got one global 'start_time' and 'running' variables. If scylla is multithreaded or more than one instance is running, that isn't going to work. To fix this, you'd want to do convert them to arrays and index them by thread ids, like this: start_time[tid()] = gettimeofday_us() 2) Your ubacktrace() call in the timer function isn't going to report what you want. At that point, you aren't running in the context of the process, you are running in the context of whatever kernel thread is running the timer. I'm really sure what a user backtrace will report at that point, but it certainly won't be useful. Here's an (untested) version of what would work a bit better: ==== global start_time probe process("/home/avi/urchin/build/release/scylla").mark("reactor_run_tasks_start") { start_time[tid()] = gettimeofday_us() } probe process("/home/avi/urchin/build/release/scylla").mark("reactor_run_tasks_end") { now = gettimeofday_us() start = start_time[tid()] delete start_time[tid()] if ((now - start) > 30000) { printf("detected tasks running for >30ms (%d)\n", (now - start)) print_usyms(ubacktrace()) } } ==== If you like, you could add a timer probe to the above to report an ongoing problem in the current process (but without printing a backtrace). -- David Smith dsmith@redhat.com Red Hat http://www.redhat.com 256.217.0141 (direct) 256.837.0057 (fax)