Commit 5d50070d authored by Brendan Gregg's avatar Brendan Gregg Committed by GitHub

Merge pull request #369 from iovisor/kstack_alias

kstack alias/replacement to stack 
parents 438fdf5b 6ec9a028
...@@ -44,7 +44,7 @@ This is a work in progress. If something is missing, check the bpftrace source t ...@@ -44,7 +44,7 @@ This is a work in progress. If something is missing, check the bpftrace source t
- [4. `count()`: Frequency Counting](#4-count-frequency-counting) - [4. `count()`: Frequency Counting](#4-count-frequency-counting)
- [5. `hist()`, `lhist()`: Histograms](#5-hist-lhist-histograms) - [5. `hist()`, `lhist()`: Histograms](#5-hist-lhist-histograms)
- [6. `nsecs`: Timestamps and Time Deltas](#6-nsecs-timestamps-and-time-deltas) - [6. `nsecs`: Timestamps and Time Deltas](#6-nsecs-timestamps-and-time-deltas)
- [7. `stack`: Stack Traces, Kernel](#7-stack-stack-traces-kernel) - [7. `kstack`: Stack Traces, Kernel](#7-kstack-stack-traces-kernel)
- [8. `ustack`: Stack Traces, User](#8-ustack-stack-traces-user) - [8. `ustack`: Stack Traces, User](#8-ustack-stack-traces-user)
- [9. `$1`, ..., `$N`: Positional Parameters](#9-1--n-positional-parameters) - [9. `$1`, ..., `$N`: Positional Parameters](#9-1--n-positional-parameters)
- [Functions](#functions) - [Functions](#functions)
...@@ -929,7 +929,7 @@ That would fire once for every 1000000 cache misses. This usually indicates the ...@@ -929,7 +929,7 @@ That would fire once for every 1000000 cache misses. This usually indicates the
- `nsecs` - Nanosecond timestamp - `nsecs` - Nanosecond timestamp
- `cpu` - Processor ID - `cpu` - Processor ID
- `comm` - Process name - `comm` - Process name
- `stack` - Kernel stack trace - `kstack` - Kernel stack trace
- `ustack` - User stack trace - `ustack` - User stack trace
- `arg0`, `arg1`, ..., `argN`. - Arguments to the traced function - `arg0`, `arg1`, ..., `argN`. - Arguments to the traced function
- `retval` - Return value from traced function - `retval` - Return value from traced function
...@@ -1052,16 +1052,16 @@ at 1438 ms: sleep ...@@ -1052,16 +1052,16 @@ at 1438 ms: sleep
^C ^C
``` ```
## 7. `stack`: Stack Traces, Kernel ## 7. `kstack`: Stack Traces, Kernel
Syntax: `stack` Syntax: `kstack`
These are implemented using BPF stack maps. These are implemented using BPF stack maps.
Examples: Examples:
``` ```
# bpftrace -e 'kprobe:ip_output { @[stack] = count(); }' # bpftrace -e 'kprobe:ip_output { @[kstack] = count(); }'
Attaching 1 probe... Attaching 1 probe...
[...] [...]
@[ @[
...@@ -1269,7 +1269,7 @@ Tracing block I/O sizes > 0 bytes ...@@ -1269,7 +1269,7 @@ Tracing block I/O sizes > 0 bytes
- `exit()` - Quit bpftrace - `exit()` - Quit bpftrace
- `cgroupid(char *path)` - Resolve cgroup ID - `cgroupid(char *path)` - Resolve cgroup ID
Some of these are asynchronous: the kernel queues the event, but some time later (milliseconds) it is processed in user-space. The asynchronous actions are: <tt>printf()</tt>, <tt>time()</tt>, and <tt>join()</tt>. Both <tt>sym()</tt> and <tt>usym()</tt>, as well as the variables <tt>stack</tt> and </tt>ustack</tt>, record addresses synchronously, but then do symbol translation asynchronously. Some of these are asynchronous: the kernel queues the event, but some time later (milliseconds) it is processed in user-space. The asynchronous actions are: <tt>printf()</tt>, <tt>time()</tt>, and <tt>join()</tt>. Both <tt>sym()</tt> and <tt>usym()</tt>, as well as the variables <tt>kstack</tt> and </tt>ustack</tt>, record addresses synchronously, but then do symbol translation asynchronously.
A selection of these are discussed in the following sections. A selection of these are discussed in the following sections.
......
...@@ -215,12 +215,12 @@ secondary_startup_64+165 ...@@ -215,12 +215,12 @@ secondary_startup_64+165
Profile kernel stacks at 99 Hertz, printing a frequency count. Profile kernel stacks at 99 Hertz, printing a frequency count.
- profile:hz:99: This fires on all CPUs at 99 Hertz. Why 99 and not 100 or 1000? We want frequent enough to catch both the big and small picture of execution, but not too frequent as to perturb performance. 100 Hertz is enough. But we don't want 100 exactly, as sampling may occur in lockstep with other timed activities, hence 99. - profile:hz:99: This fires on all CPUs at 99 Hertz. Why 99 and not 100 or 1000? We want frequent enough to catch both the big and small picture of execution, but not too frequent as to perturb performance. 100 Hertz is enough. But we don't want 100 exactly, as sampling may occur in lockstep with other timed activities, hence 99.
- stack: Returns the kernel stack trace. This is used as a key for the map, so that it can be frequency counted. The output of this is ideal to be visualized as a flame graph. There is also `ustack` for the user-level stack trace. - kstack: Returns the kernel stack trace. This is used as a key for the map, so that it can be frequency counted. The output of this is ideal to be visualized as a flame graph. There is also `ustack` for the user-level stack trace.
# Lesson 10. Scheduler Tracing # Lesson 10. Scheduler Tracing
``` ```
# bpftrace -e 'tracepoint:sched:sched_switch { @[stack] = count(); }' # bpftrace -e 'tracepoint:sched:sched_switch { @[kstack] = count(); }'
^C ^C
[...] [...]
...@@ -248,8 +248,8 @@ This counts stack traces that led to context switching (off-CPU) events. The abo ...@@ -248,8 +248,8 @@ This counts stack traces that led to context switching (off-CPU) events. The abo
- sched: The sched category has tracepoints for different kernel CPU scheduler events: sched_switch, sched_wakeup, sched_migrate_task, etc. - sched: The sched category has tracepoints for different kernel CPU scheduler events: sched_switch, sched_wakeup, sched_migrate_task, etc.
- sched_switch: This probe fires when a thread leaves CPU. This will be a blocking event: eg, waiting on I/O, a timer, paging/swapping, or a lock. - sched_switch: This probe fires when a thread leaves CPU. This will be a blocking event: eg, waiting on I/O, a timer, paging/swapping, or a lock.
- stack: A kernel stack trace. - kstack: A kernel stack trace.
- sched_switch fires in thread context, so that the stack refers to the thread who is leaving. As you use other probe types, pay attention to context, as comm, pid, stack, etc, may not refer to the target of the probe. - sched_switch fires in thread context, so that the stack refers to the thread who is leaving. As you use other probe types, pay attention to context, as comm, pid, kstack, etc, may not refer to the target of the probe.
# Lesson 11. Block I/O Tracing # Lesson 11. Block I/O Tracing
......
#pragma once #pragma once
#include <iostream>
#include <string> #include <string>
#include <vector> #include <vector>
#include <map> #include <map>
...@@ -9,6 +10,8 @@ ...@@ -9,6 +10,8 @@
namespace bpftrace { namespace bpftrace {
namespace ast { namespace ast {
static bool PRINT_STACK_DEPRICATED = true;
class Visitor; class Visitor;
class Node { class Node {
...@@ -56,7 +59,17 @@ public: ...@@ -56,7 +59,17 @@ public:
class Builtin : public Expression { class Builtin : public Expression {
public: public:
explicit Builtin(std::string ident) : ident(ident) { } explicit Builtin(std::string ident) : ident(ident) {
if (ident == "stack") {
if (PRINT_STACK_DEPRICATED)
{
std::cerr << "warning: stack is deprecated and will be removed in the future. Use kstack instead" << std::endl;
PRINT_STACK_DEPRICATED = false;
}
this->ident = "kstack";
}
}
std::string ident; std::string ident;
int probe_id; int probe_id;
......
...@@ -49,7 +49,7 @@ void CodegenLLVM::visit(Builtin &builtin) ...@@ -49,7 +49,7 @@ void CodegenLLVM::visit(Builtin &builtin)
{ {
expr_ = b_.CreateGetNs(); expr_ = b_.CreateGetNs();
} }
else if (builtin.ident == "stack" || builtin.ident == "ustack") else if (builtin.ident == "kstack" || builtin.ident == "ustack")
{ {
Value *stackid = b_.CreateGetStackId(ctx_, builtin.ident == "ustack"); Value *stackid = b_.CreateGetStackId(ctx_, builtin.ident == "ustack");
// Kernel stacks should not be differentiated by tid, since the kernel // Kernel stacks should not be differentiated by tid, since the kernel
......
...@@ -60,8 +60,8 @@ void SemanticAnalyser::visit(Builtin &builtin) ...@@ -60,8 +60,8 @@ void SemanticAnalyser::visit(Builtin &builtin)
builtin.ident == "retval") { builtin.ident == "retval") {
builtin.type = SizedType(Type::integer, 8); builtin.type = SizedType(Type::integer, 8);
} }
else if (builtin.ident == "stack") { else if (builtin.ident == "kstack") {
builtin.type = SizedType(Type::stack, 8); builtin.type = SizedType(Type::kstack, 8);
needs_stackid_map_ = true; needs_stackid_map_ = true;
} }
else if (builtin.ident == "ustack") { else if (builtin.ident == "ustack") {
......
...@@ -420,7 +420,7 @@ std::vector<std::unique_ptr<IPrintable>> BPFtrace::get_arg_values(const std::vec ...@@ -420,7 +420,7 @@ std::vector<std::unique_ptr<IPrintable>> BPFtrace::get_arg_values(const std::vec
resolve_probe( resolve_probe(
*reinterpret_cast<uint64_t*>(arg_data+arg.offset)))); *reinterpret_cast<uint64_t*>(arg_data+arg.offset))));
break; break;
case Type::stack: case Type::kstack:
arg_values.push_back( arg_values.push_back(
std::make_unique<PrintableString>( std::make_unique<PrintableString>(
get_stack( get_stack(
...@@ -878,7 +878,7 @@ int BPFtrace::print_map(IMap &map, uint32_t top, uint32_t div) ...@@ -878,7 +878,7 @@ int BPFtrace::print_map(IMap &map, uint32_t top, uint32_t div)
std::cout << map.name_ << map.key_.argument_value_list(*this, key) << ": "; std::cout << map.name_ << map.key_.argument_value_list(*this, key) << ": ";
if (map.type_.type == Type::stack) if (map.type_.type == Type::kstack)
std::cout << get_stack(*(uint64_t*)value.data(), false, 8); std::cout << get_stack(*(uint64_t*)value.data(), false, 8);
else if (map.type_.type == Type::ustack) else if (map.type_.type == Type::ustack)
std::cout << get_stack(*(uint64_t*)value.data(), true, 8); std::cout << get_stack(*(uint64_t*)value.data(), true, 8);
......
...@@ -49,7 +49,7 @@ path :(\\.|[_\-\./a-zA-Z0-9])*: ...@@ -49,7 +49,7 @@ path :(\\.|[_\-\./a-zA-Z0-9])*:
<COMMENT>"*/" BEGIN(INITIAL); <COMMENT>"*/" BEGIN(INITIAL);
<COMMENT>"EOF" driver.error(loc, std::string("end of file during comment")); <COMMENT>"EOF" driver.error(loc, std::string("end of file during comment"));
pid|tid|cgroup|uid|gid|nsecs|cpu|comm|stack|ustack|arg[0-9]|retval|func|probe|curtask|rand|ctx|username|args { pid|tid|cgroup|uid|gid|nsecs|cpu|comm|kstack|stack|ustack|arg[0-9]|retval|func|probe|curtask|rand|ctx|username|args {
return Parser::make_BUILTIN(yytext, loc); } return Parser::make_BUILTIN(yytext, loc); }
{path} { return Parser::make_PATH(yytext, loc); } {path} { return Parser::make_PATH(yytext, loc); }
{map} { return Parser::make_MAP(yytext, loc); } {map} { return Parser::make_MAP(yytext, loc); }
......
...@@ -71,7 +71,7 @@ std::string MapKey::argument_value(BPFtrace &bpftrace, ...@@ -71,7 +71,7 @@ std::string MapKey::argument_value(BPFtrace &bpftrace,
return std::to_string(*(int64_t*)data); return std::to_string(*(int64_t*)data);
break; break;
} }
case Type::stack: case Type::kstack:
return bpftrace.get_stack(*(uint64_t*)data, false); return bpftrace.get_stack(*(uint64_t*)data, false);
case Type::ustack: case Type::ustack:
return bpftrace.get_stack(*(uint64_t*)data, true); return bpftrace.get_stack(*(uint64_t*)data, true);
......
...@@ -34,7 +34,7 @@ std::string verify_format_string(const std::string &fmt, std::vector<Field> args ...@@ -34,7 +34,7 @@ std::string verify_format_string(const std::string &fmt, std::vector<Field> args
{ {
Type arg_type = args.at(i).type.type; Type arg_type = args.at(i).type.type;
if (arg_type == Type::sym || arg_type == Type::usym || arg_type == Type::probe || if (arg_type == Type::sym || arg_type == Type::usym || arg_type == Type::probe ||
arg_type == Type::username || arg_type == Type::stack || arg_type == Type::ustack || arg_type == Type::username || arg_type == Type::kstack || arg_type == Type::ustack ||
arg_type == Type::inet) arg_type == Type::inet)
arg_type = Type::string; // Symbols should be printed as strings arg_type = Type::string; // Symbols should be printed as strings
int offset = 1; int offset = 1;
......
...@@ -43,7 +43,7 @@ std::string typestr(Type t) ...@@ -43,7 +43,7 @@ std::string typestr(Type t)
case Type::max: return "max"; break; case Type::max: return "max"; break;
case Type::avg: return "avg"; break; case Type::avg: return "avg"; break;
case Type::stats: return "stats"; break; case Type::stats: return "stats"; break;
case Type::stack: return "stack"; break; case Type::kstack: return "kstack"; break;
case Type::ustack: return "ustack"; break; case Type::ustack: return "ustack"; break;
case Type::string: return "string"; break; case Type::string: return "string"; break;
case Type::sym: return "sym"; break; case Type::sym: return "sym"; break;
......
...@@ -24,7 +24,7 @@ enum class Type ...@@ -24,7 +24,7 @@ enum class Type
max, max,
avg, avg,
stats, stats,
stack, kstack,
ustack, ustack,
string, string,
sym, sym,
......
#include "common.h"
namespace bpftrace {
namespace test {
namespace codegen {
TEST(codegen, builtin_stack)
{
test("kprobe:f { @x = kstack }",
R"EXPECTED(; Function Attrs: nounwind
declare i64 @llvm.bpf.pseudo(i64, i64) #0
; Function Attrs: argmemonly nounwind
declare void @llvm.lifetime.start.p0i8(i64, i8* nocapture) #1
define i64 @"kprobe:f"(i8*) local_unnamed_addr section "s_kprobe:f_1" {
entry:
%"@x_val" = alloca i64, align 8
%"@x_key" = alloca i64, align 8
%pseudo = tail call i64 @llvm.bpf.pseudo(i64 1, i64 2)
%get_stackid = tail call i64 inttoptr (i64 27 to i64 (i8*, i8*, i64)*)(i8* %0, i64 %pseudo, i64 0)
%1 = bitcast i64* %"@x_key" to i8*
call void @llvm.lifetime.start.p0i8(i64 -1, i8* nonnull %1)
store i64 0, i64* %"@x_key", align 8
%2 = bitcast i64* %"@x_val" to i8*
call void @llvm.lifetime.start.p0i8(i64 -1, i8* nonnull %2)
store i64 %get_stackid, i64* %"@x_val", align 8
%pseudo1 = tail call i64 @llvm.bpf.pseudo(i64 1, i64 1)
%update_elem = call i64 inttoptr (i64 2 to i64 (i8*, i8*, i8*, i64)*)(i64 %pseudo1, i64* nonnull %"@x_key", i64* nonnull %"@x_val", i64 0)
call void @llvm.lifetime.end.p0i8(i64 -1, i8* nonnull %1)
call void @llvm.lifetime.end.p0i8(i64 -1, i8* nonnull %2)
ret i64 0
}
; Function Attrs: argmemonly nounwind
declare void @llvm.lifetime.end.p0i8(i64, i8* nocapture) #1
attributes #0 = { nounwind }
attributes #1 = { argmemonly nounwind }
)EXPECTED");
}
} // namespace codegen
} // namespace test
} // namespace bpftrace
...@@ -35,7 +35,8 @@ TEST(Parser, builtin_variables) ...@@ -35,7 +35,8 @@ TEST(Parser, builtin_variables)
test("kprobe:f { rand }", "Program\n kprobe:f\n builtin: rand\n"); test("kprobe:f { rand }", "Program\n kprobe:f\n builtin: rand\n");
test("kprobe:f { ctx }", "Program\n kprobe:f\n builtin: ctx\n"); test("kprobe:f { ctx }", "Program\n kprobe:f\n builtin: ctx\n");
test("kprobe:f { comm }", "Program\n kprobe:f\n builtin: comm\n"); test("kprobe:f { comm }", "Program\n kprobe:f\n builtin: comm\n");
test("kprobe:f { stack }", "Program\n kprobe:f\n builtin: stack\n"); test("kprobe:f { stack }", "Program\n kprobe:f\n builtin: kstack\n");
test("kprobe:f { kstack }", "Program\n kprobe:f\n builtin: kstack\n");
test("kprobe:f { ustack }", "Program\n kprobe:f\n builtin: ustack\n"); test("kprobe:f { ustack }", "Program\n kprobe:f\n builtin: ustack\n");
test("kprobe:f { arg0 }", "Program\n kprobe:f\n builtin: arg0\n"); test("kprobe:f { arg0 }", "Program\n kprobe:f\n builtin: arg0\n");
test("kprobe:f { retval }", "Program\n kprobe:f\n builtin: retval\n"); test("kprobe:f { retval }", "Program\n kprobe:f\n builtin: retval\n");
......
...@@ -41,6 +41,12 @@ EXPECT SUCCESS stack ...@@ -41,6 +41,12 @@ EXPECT SUCCESS stack
TIMEOUT 5 TIMEOUT 5
BEFORE sleep 1 && sleep 1 & BEFORE sleep 1 && sleep 1 &
NAME kstack
RUN bpftrace -e 'k:do_nanosleep { printf("SUCCESS '$test' %s\n", kstack); exit(); }'
EXPECT SUCCESS kstack
TIMEOUT 5
BEFORE sleep 1 && sleep 1 &
NAME ustack NAME ustack
RUN bpftrace -e 'k:do_nanosleep { printf("SUCCESS '$test' %s\n", ustack); exit(); }' RUN bpftrace -e 'k:do_nanosleep { printf("SUCCESS '$test' %s\n", ustack); exit(); }'
EXPECT SUCCESS ustack EXPECT SUCCESS ustack
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment