bcc/tools/old/offwaketime.py at ctf · dqminh/bcc

Repository navigation

History

100

101

102

103

104

105

106

107

108

109

110

111

112

113

114

115

116

117

118

119

120

121

122

123

124

125

126

127

128

129

130

131

132

133

134

135

136

137

138

139

140

141

142

143

144

145

146

147

148

149

150

151

152

153

154

155

156

157

158

159

160

161

162

163

164

165

166

167

168

169

170

171

172

173

174

175

176

177

178

179

180

181

182

183

184

185

186

187

188

189

190

191

192

193

194

195

196

197

198

199

200

201

202

203

204

205

206

207

208

209

210

211

212

213

214

215

216

217

218

219

220

221

222

223

224

225

226

227

228

229

230

231

232

233

234

235

236

237

238

239

240

241

242

243

244

245

246

247

248

249

250

251

252

253

254

255

256

257

258

259

260

261

262

263

264

265

266

267

268

269

270

271

272

273

274

275

276

277

278

279

280

281

282

283

284

#!/usr/bin/python

# offwaketime Summarize blocked time by kernel off-CPU stack + waker stack

# For Linux, uses BCC, eBPF.

# USAGE: offwaketime [-h] [-u] [-p PID] [-T] [duration]

# The current implementation uses an unrolled loop for x86_64, and was written

# as a proof of concept. This implementation should be replaced in the future

# with an appropriate bpf_ call, when available.

# The Off-CPU stack is currently limited to a stack trace depth of 20

# (maxtdepth), and the waker stack limited to 10 (maxwdepth). This is also

# limited to kernel stacks, and x86_64 only. Check for future versions, where

# these limitations should be removed.

# Licensed under the Apache License, Version 2.0 (the "License")

# 20-Jan-2016 Brendan Gregg Created this.

from __future__ import print_function

from bcc import BPF

from time import sleep

import argparse

import signal

# arguments

examples = """examples:

./offwaketime # trace off-CPU + waker stack time until Ctrl-C

./offwaketime 5 # trace for 5 seconds only

./offwaketime -f 5 # 5 seconds, and output in folded format

./offwaketime -u # don't include kernel threads (user only)

./offwaketime -p 185 # trace fo PID 185 only

"""

parser = argparse.ArgumentParser(

description="Summarize blocked time by kernel stack trace + waker stack",

formatter_class=argparse.RawDescriptionHelpFormatter,

epilog=examples)

parser.add_argument("-u", "--useronly", action="store_true",

help="user threads only (no kernel threads)")

parser.add_argument("-p", "--pid",

help="trace this PID only")

parser.add_argument("-v", "--verbose", action="store_true",

help="show raw addresses")

parser.add_argument("-f", "--folded", action="store_true",

help="output folded format")

parser.add_argument("duration", nargs="?", default=99999999,

help="duration of trace, in seconds")

args = parser.parse_args()

folded = args.folded

duration = int(args.duration)

debug = 0

maxwdepth = 10 # and MAXWDEPTH

maxtdepth = 20 # and MAXTDEPTH

if args.pid and args.useronly:

print("ERROR: use either -p or -u.")

exit()

# signal handler

def signal_ignore(signal, frame):

print()

# define BPF program

bpf_text = """

#include <uapi/linux/ptrace.h>

#include <linux/sched.h>

#define MAXWDEPTH 10

#define MAXTDEPTH 20

#define MINBLOCK_US 1

struct key_t {

char waker[TASK_COMM_LEN];

char target[TASK_COMM_LEN];

u64 wret[MAXWDEPTH];

u64 tret[MAXTDEPTH];

};

BPF_HASH(counts, struct key_t);

BPF_HASH(start, u32);

struct wokeby_t {

char name[TASK_COMM_LEN];

u64 ret[MAXWDEPTH];

};

BPF_HASH(wokeby, u32, struct wokeby_t);

static u64 get_frame(u64 *bp) {

if (*bp) {

// The following stack walker is x86_64 specific

u64 ret = 0;

if (bpf_probe_read(&ret, sizeof(ret), (void *)(*bp+8)))

return 0;

if (bpf_probe_read(bp, sizeof(*bp), (void *)*bp))

*bp = 0;

if (ret < __START_KERNEL_map)

return 0;

return ret;

}

return 0;

}

int waker(struct pt_regs *ctx, struct task_struct *p) {

u32 pid = p->pid;

if (!(FILTER))

return 0;

u64 bp = 0;

struct wokeby_t woke = {};

int depth = 0;

bpf_get_current_comm(&woke.name, sizeof(woke.name));

bp = ctx->bp;

// unrolled loop (MAXWDEPTH):

if (!(woke.ret[depth++] = get_frame(&bp))) goto out;

woke.ret[depth] = get_frame(&bp);

out:

wokeby.update(&pid, &woke);

return 0;

}

int oncpu(struct pt_regs *ctx, struct task_struct *p) {

u32 pid = p->pid;

u64 ts, *tsp;

// record previous thread sleep time

if (FILTER) {

ts = bpf_ktime_get_ns();

start.update(&pid, &ts);

}

// calculate current thread's delta time

pid = bpf_get_current_pid_tgid();

tsp = start.lookup(&pid);

if (tsp == 0)

return 0; // missed start or filtered

u64 delta = bpf_ktime_get_ns() - *tsp;

start.delete(&pid);

delta = delta / 1000;

if (delta < MINBLOCK_US)

return 0;

// create map key

u64 zero = 0, *val, bp = 0;

int depth = 0;

struct key_t key = {};

struct wokeby_t *woke;

bpf_get_current_comm(&key.target, sizeof(key.target));

bp = ctx->bp;

// unrolled loop (MAXTDEPTH):

if (!(key.tret[depth++] = get_frame(&bp))) goto out;

key.tret[depth] = get_frame(&bp);

out:

woke = wokeby.lookup(&pid);

if (woke) {

__builtin_memcpy(&key.wret, woke->ret, sizeof(key.wret));

__builtin_memcpy(&key.waker, woke->name, TASK_COMM_LEN);

wokeby.delete(&pid);

}

val = counts.lookup_or_init(&key, &zero);

(*val) += delta;

return 0;

}

"""

if args.pid:

filter = 'pid == %s' % args.pid

elif args.useronly:

filter = '!(p->flags & PF_KTHREAD)'

else:

filter = '1'

bpf_text = bpf_text.replace('FILTER', filter)

if debug:

print(bpf_text)

# initialize BPF

b = BPF(text=bpf_text)

b.attach_kprobe(event="finish_task_switch", fn_name="oncpu")

b.attach_kprobe(event="try_to_wake_up", fn_name="waker")

matched = b.num_open_kprobes()

if matched == 0:

print("0 functions traced. Exiting.")

exit()

# header

if not folded:

print("Tracing blocked time (us) by kernel off-CPU and waker stack",

end="")

if duration < 99999999:

print(" for %d secs." % duration)

else:

print("... Hit Ctrl-C to end.")

# output

while (1):

try:

sleep(duration)

except KeyboardInterrupt:

# as cleanup can take many seconds, trap Ctrl-C:

signal.signal(signal.SIGINT, signal_ignore)

if not folded:

print()

counts = b.get_table("counts")

for k, v in sorted(counts.items(), key=lambda counts: counts[1].value):

if folded:

# fold target stack

line = k.target + ";"

for i in reversed(range(0, maxtdepth)):

if k.tret[i] == 0:

continue

line = line + b.ksym(k.tret[i])

if i != 0:

line = line + ";"

# add delimiter

line = line + ";-"

# fold waker stack

for i in range(0, maxwdepth):

line = line + ";"

if k.wret[i] == 0:

break

line = line + b.ksym(k.wret[i])

if i != 0:

line = line + ";" + k.waker

# print as a line

print("%s %d" % (line, v.value))

else:

# print wakeup name then stack in reverse order

print(" %-16s %s" % ("waker:", k.waker))

for i in reversed(range(0, maxwdepth)):

if k.wret[i] == 0:

continue

print(" %-16x %s" % (k.wret[i],

b.ksym(k.wret[i])))

# print delimiter

print(" %-16s %s" % ("-", "-"))

# print default multi-line stack output

for i in range(0, maxtdepth):

if k.tret[i] == 0:

break

print(" %-16x %s" % (k.tret[i],

b.ksym(k.tret[i])))

print(" %-16s %s" % ("target:", k.target))

print(" %d\n" % v.value)

counts.clear()

if not folded:

print("Detaching...")

exit()

FilesExpand file tree

offwaketime.py

Latest commit

History

offwaketime.py

File metadata and controls